From neteng, 8 Years ago, written in FreeSWITCH.
- view diff
Embed
  1. NOT:WORKING:
  2. 2016-05-17 21:26:58.897799 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/2002@bes2.sip.urbancom.net:5060 [c453b31f-8773-40cc-bbaa-43eb322f839f]
  3. 2016-05-17 21:26:58.897799 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/2002@bes2.sip.urbancom.net:5060) Running State Change CS_NEW
  4. 2016-05-17 21:26:58.897799 [DEBUG] sofia.c:9376 sofia/internal/2002@bes2.sip.urbancom.net:5060 receiving invite from 73.72.98.76:5060 version: 1.6.8 -15-99de0ad 64bit
  5. 2016-05-17 21:26:58.897799 [DEBUG] sofia.c:9543 IP 73.72.98.76 Rejected by acl "domains". Falling back to Digest auth.
  6. 2016-05-17 21:26:58.897799 [WARNING] sofia_reg.c:1775 SIP auth challenge (INVITE) on sofia profile 'internal' for [17085143073@bes2.sip.urbancom.net] from ip 73.72.98.76
  7. 2016-05-17 21:26:58.897799 [DEBUG] switch_core_state_machine.c:562 (sofia/internal/2002@bes2.sip.urbancom.net:5060) State NEW
  8. 2016-05-17 21:26:58.897799 [DEBUG] sofia.c:2214 detaching session c453b31f-8773-40cc-bbaa-43eb322f839f
  9. 2016-05-17 21:26:58.977861 [DEBUG] sofia.c:2322 Re-attaching to session c453b31f-8773-40cc-bbaa-43eb322f839f
  10. 2016-05-17 21:26:58.997808 [DEBUG] sofia.c:9376 sofia/internal/2002@bes2.sip.urbancom.net:5060 receiving invite from 73.72.98.76:5060 version: 1.6.8 -15-99de0ad 64bit
  11. 2016-05-17 21:26:58.997808 [DEBUG] sofia.c:9543 IP 73.72.98.76 Rejected by acl "domains". Falling back to Digest auth.
  12. 2016-05-17 21:26:58.997808 [DEBUG] sofia.c:6858 Channel sofia/internal/2002@bes2.sip.urbancom.net:5060 entering state [received][100]
  13. 2016-05-17 21:26:58.997808 [DEBUG] sofia.c:6868 Remote SDP:
  14. v=0
  15. o=- 20008 20008 IN IP4 73.72.98.76
  16. s=SDP data
  17. c=IN IP4 73.72.98.76
  18. t=0 0
  19. m=audio 11796 RTP/AVP 0 8 18 9 101
  20. a=rtpmap:0 PCMU/8000
  21. a=rtpmap:8 PCMA/8000
  22. a=rtpmap:18 G729/8000
  23. a=fmtp:18 annexb=no
  24. a=rtpmap:9 G722/8000
  25. a=rtpmap:101 telephone-event/8000
  26. a=fmtp:101 0-15
  27. a=ptime:20
  28.  
  29. 2016-05-17 21:26:58.997808 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  30. 2016-05-17 21:26:58.997808 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  31. 2016-05-17 21:26:58.997808 [DEBUG] switch_core_media.c:4410 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
  32. 2016-05-17 21:26:58.997808 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  33. 2016-05-17 21:26:58.997808 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
  34. 2016-05-17 21:26:58.997808 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  35. 2016-05-17 21:26:58.997808 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  36. 2016-05-17 21:26:58.997808 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  37. 2016-05-17 21:26:58.997808 [DEBUG] switch_core_media.c:4410 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
  38. 2016-05-17 21:26:58.997808 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
  39. 2016-05-17 21:26:58.997808 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [G729:18:8000:20:8000:1]/[G722:9:8000:20:64000:1]
  40. 2016-05-17 21:26:58.997808 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
  41. 2016-05-17 21:26:58.997808 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
  42. 2016-05-17 21:26:58.997808 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [G729:18:8000:20:8000:1]/[GSM:3:8000:20:13200:1]
  43. 2016-05-17 21:26:58.997808 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  44. 2016-05-17 21:26:58.997808 [DEBUG] switch_core_media.c:4410 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match
  45. 2016-05-17 21:26:58.997808 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  46. 2016-05-17 21:26:58.997808 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  47. 2016-05-17 21:26:58.997808 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [G722:9:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
  48. 2016-05-17 21:26:58.997808 [DEBUG] switch_core_media.c:4271 Set telephone-event payload to 101@8000
  49. 2016-05-17 21:26:58.997808 [DEBUG] switch_core_media.c:3090 Set Codec sofia/internal/2002@bes2.sip.urbancom.net:5060 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
  50. 2016-05-17 21:26:58.997808 [DEBUG] switch_core_codec.c:111 sofia/internal/2002@bes2.sip.urbancom.net:5060 Original read codec set to PCMU:0
  51. 2016-05-17 21:26:58.997808 [DEBUG] switch_core_media.c:4623 Set telephone-event payload to 101@8000
  52. 2016-05-17 21:26:58.997808 [DEBUG] switch_core_media.c:4681 sofia/internal/2002@bes2.sip.urbancom.net:5060 Set 2833 dtmf send payload to 101 recv payload to 101
  53. 2016-05-17 21:26:58.997808 [DEBUG] sofia.c:7248 (sofia/internal/2002@bes2.sip.urbancom.net:5060) State Change CS_NEW -> CS_INIT
  54. 2016-05-17 21:26:58.997808 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/2002@bes2.sip.urbancom.net:5060) Running State Change CS_INIT
  55. 2016-05-17 21:26:58.997808 [DEBUG] switch_core_state_machine.c:586 (sofia/internal/2002@bes2.sip.urbancom.net:5060) State INIT
  56. 2016-05-17 21:26:58.997808 [DEBUG] mod_sofia.c:89 sofia/internal/2002@bes2.sip.urbancom.net:5060 SOFIA INIT
  57. 2016-05-17 21:26:58.997808 [DEBUG] switch_core_state_machine.c:40 sofia/internal/2002@bes2.sip.urbancom.net:5060 Standard INIT
  58. 2016-05-17 21:26:58.997808 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/2002@bes2.sip.urbancom.net:5060) State Change CS_INIT -> CS_ROUTING
  59. 2016-05-17 21:26:58.997808 [DEBUG] switch_core_state_machine.c:586 (sofia/internal/2002@bes2.sip.urbancom.net:5060) State INIT going to sleep
  60. 2016-05-17 21:26:58.997808 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/2002@bes2.sip.urbancom.net:5060) Running State Change CS_ROUTING
  61. 2016-05-17 21:26:58.997808 [DEBUG] switch_channel.c:2249 (sofia/internal/2002@bes2.sip.urbancom.net:5060) Callstate Change DOWN -> RINGING
  62. 2016-05-17 21:26:58.997808 [DEBUG] switch_core_state_machine.c:602 (sofia/internal/2002@bes2.sip.urbancom.net:5060) State ROUTING
  63. 2016-05-17 21:26:58.997808 [DEBUG] mod_sofia.c:142 sofia/internal/2002@bes2.sip.urbancom.net:5060 SOFIA ROUTING
  64. 2016-05-17 21:26:58.997808 [DEBUG] switch_core_state_machine.c:236 sofia/internal/2002@bes2.sip.urbancom.net:5060 Standard ROUTING
  65. 2016-05-17 21:26:58.997808 [INFO] mod_dialplan_xml.c:637 Processing 2002 <2002>->17085143073 in context bes2.sip.urbancom.net
  66. Dialplan: sofia/internal/2002@bes2.sip.urbancom.net:5060 parsing [bes2.sip.urbancom.net->user_exists] continue=true
  67. Dialplan: sofia/internal/2002@bes2.sip.urbancom.net:5060 Regex (PASS) [user_exists] () =~ // break=on-false
  68. Dialplan: sofia/internal/2002@bes2.sip.urbancom.net:5060 Action set(user_exists=${user_exists id ${destination_number} ${domain_name}}) INLINE
  69. 2016-05-17 21:26:59.017797 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7fa65402aa40 Connected.
  70. 2016-05-17 21:26:59.017797 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7fa65402aa40 released.
  71. EXECUTE sofia/internal/2002@bes2.sip.urbancom.net:5060 set(user_exists=false)
  72. 2016-05-17 21:26:59.017797 [DEBUG] mod_dptools.c:1519 SET sofia/internal/2002@bes2.sip.urbancom.net:5060 [user_exists]=[false]
  73. Dialplan: sofia/internal/2002@bes2.sip.urbancom.net:5060 Regex (FAIL) [user_exists] ${user_exists}(false) =~ /^true$/ break=on-false
  74. Dialplan: sofia/internal/2002@bes2.sip.urbancom.net:5060 parsing [bes2.sip.urbancom.net->call-direction] continue=true
  75. Dialplan: sofia/internal/2002@bes2.sip.urbancom.net:5060 Regex (FAIL) [call-direction] ${call_direction}() =~ /^(inbound|outbound|local)$/ break=never
  76. Dialplan: sofia/internal/2002@bes2.sip.urbancom.net:5060 ANTI-Action set(call_direction=local)
  77. Dialplan: sofia/internal/2002@bes2.sip.urbancom.net:5060 parsing [bes2.sip.urbancom.net->variables] continue=true
  78. Dialplan: sofia/internal/2002@bes2.sip.urbancom.net:5060 Regex (PASS) [variables] () =~ // break=on-false
  79. Dialplan: sofia/internal/2002@bes2.sip.urbancom.net:5060 Action export(origination_callee_id_name=${destination_number})
  80. Dialplan: sofia/internal/2002@bes2.sip.urbancom.net:5060 Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
  81. Dialplan: sofia/internal/2002@bes2.sip.urbancom.net:5060 parsing [bes2.sip.urbancom.net->user_record] continue=true
  82. Dialplan: sofia/internal/2002@bes2.sip.urbancom.net:5060 Regex (PASS) [user_record] () =~ // break=on-false
  83. Dialplan: sofia/internal/2002@bes2.sip.urbancom.net:5060 Action set(user_record=${user_data ${destination_number}@${domain_name} var user_record}) INLINE
  84. 2016-05-17 21:26:59.037790 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7fa65402aa40 Connected.
  85. 2016-05-17 21:26:59.037790 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7fa65402aa40 released.
  86. 2016-05-17 21:26:59.037790 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7fa65402aa40 Connected.
  87. 2016-05-17 21:26:59.037790 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7fa65402aa40 released.
  88. EXECUTE sofia/internal/2002@bes2.sip.urbancom.net:5060 set(user_record=)
  89. 2016-05-17 21:26:59.037790 [DEBUG] mod_dptools.c:1519 SET sofia/internal/2002@bes2.sip.urbancom.net:5060 [user_record]=[UNDEF]
  90. Dialplan: sofia/internal/2002@bes2.sip.urbancom.net:5060 Action set(from_user_exists=${user_exists id ${sip_from_user} ${sip_from_host}}) INLINE
  91. EXECUTE sofia/internal/2002@bes2.sip.urbancom.net:5060 set(from_user_exists=true)
  92. 2016-05-17 21:26:59.037790 [DEBUG] mod_dptools.c:1519 SET sofia/internal/2002@bes2.sip.urbancom.net:5060 [from_user_exists]=[true]
  93. Dialplan: sofia/internal/2002@bes2.sip.urbancom.net:5060 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
  94. Dialplan: sofia/internal/2002@bes2.sip.urbancom.net:5060 Regex (FAIL) [user_record] ${user_record}() =~ /^all$/ break=never
  95. Dialplan: sofia/internal/2002@bes2.sip.urbancom.net:5060 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
  96. Dialplan: sofia/internal/2002@bes2.sip.urbancom.net:5060 Regex (FAIL) [user_record] ${call_direction}() =~ /^inbound$/ break=never
  97. Dialplan: sofia/internal/2002@bes2.sip.urbancom.net:5060 Regex (FAIL) [user_record] ${user_record}() =~ /^inbound$/ break=never
  98. Dialplan: sofia/internal/2002@bes2.sip.urbancom.net:5060 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
  99. Dialplan: sofia/internal/2002@bes2.sip.urbancom.net:5060 Regex (FAIL) [user_record] ${call_direction}() =~ /^outbound$/ break=never
  100. Dialplan: sofia/internal/2002@bes2.sip.urbancom.net:5060 Regex (FAIL) [user_record] ${user_record}() =~ /^outbound$/ break=never
  101. Dialplan: sofia/internal/2002@bes2.sip.urbancom.net:5060 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
  102. Dialplan: sofia/internal/2002@bes2.sip.urbancom.net:5060 Regex (FAIL) [user_record] ${call_direction}() =~ /^local$/ break=never
  103. Dialplan: sofia/internal/2002@bes2.sip.urbancom.net:5060 Regex (FAIL) [user_record] ${user_record}() =~ /^local$/ break=never
  104. Dialplan: sofia/internal/2002@bes2.sip.urbancom.net:5060 Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
  105. Dialplan: sofia/internal/2002@bes2.sip.urbancom.net:5060 Action set(from_user_record=${user_data ${sip_from_user}@${sip_from_host} var user_record}) INLINE
  106. EXECUTE sofia/internal/2002@bes2.sip.urbancom.net:5060 set(from_user_record=)
  107. 2016-05-17 21:26:59.037790 [DEBUG] mod_dptools.c:1519 SET sofia/internal/2002@bes2.sip.urbancom.net:5060 [from_user_record]=[UNDEF]
  108. Dialplan: sofia/internal/2002@bes2.sip.urbancom.net:5060 Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
  109. Dialplan: sofia/internal/2002@bes2.sip.urbancom.net:5060 Regex (FAIL) [user_record] ${from_user_record}() =~ /^all$/ break=never
  110. Dialplan: sofia/internal/2002@bes2.sip.urbancom.net:5060 Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
  111. Dialplan: sofia/internal/2002@bes2.sip.urbancom.net:5060 Regex (FAIL) [user_record] ${call_direction}() =~ /^inbound$/ break=never
  112. Dialplan: sofia/internal/2002@bes2.sip.urbancom.net:5060 Regex (FAIL) [user_record] ${from_user_record}() =~ /^inbound$/ break=never
  113. Dialplan: sofia/internal/2002@bes2.sip.urbancom.net:5060 Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
  114. Dialplan: sofia/internal/2002@bes2.sip.urbancom.net:5060 Regex (FAIL) [user_record] ${call_direction}() =~ /^outbound$/ break=never
  115. Dialplan: sofia/internal/2002@bes2.sip.urbancom.net:5060 Regex (FAIL) [user_record] ${from_user_record}() =~ /^outbound$/ break=never
  116. Dialplan: sofia/internal/2002@bes2.sip.urbancom.net:5060 Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
  117. Dialplan: sofia/internal/2002@bes2.sip.urbancom.net:5060 Regex (FAIL) [user_record] ${call_direction}() =~ /^local$/ break=never
  118. Dialplan: sofia/internal/2002@bes2.sip.urbancom.net:5060 Regex (FAIL) [user_record] ${from_user_record}() =~ /^local$/ break=never
  119. Dialplan: sofia/internal/2002@bes2.sip.urbancom.net:5060 Regex (FAIL) [user_record] ${record_session}() =~ /^true$/ break=on-false
  120. Dialplan: sofia/internal/2002@bes2.sip.urbancom.net:5060 parsing [bes2.sip.urbancom.net->redial] continue=true
  121. Dialplan: sofia/internal/2002@bes2.sip.urbancom.net:5060 Regex (FAIL) [redial] destination_number(17085143073) =~ /^(redial|\*870)$/ break=on-true
  122. Dialplan: sofia/internal/2002@bes2.sip.urbancom.net:5060 Regex (PASS) [redial] () =~ // break=never
  123. Dialplan: sofia/internal/2002@bes2.sip.urbancom.net:5060 Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
  124. Dialplan: sofia/internal/2002@bes2.sip.urbancom.net:5060 parsing [bes2.sip.urbancom.net->sip.urbancom.net.11d] continue=false
  125. Dialplan: sofia/internal/2002@bes2.sip.urbancom.net:5060 Regex (PASS) [sip.urbancom.net.11d] destination_number(17085143073) =~ /^\+?(\d{11})$/ break=on-false
  126. Dialplan: sofia/internal/2002@bes2.sip.urbancom.net:5060 Action set(sip_h_X-accountcode=${accountcode})
  127. Dialplan: sofia/internal/2002@bes2.sip.urbancom.net:5060 Action set(call_direction=outbound)
  128. Dialplan: sofia/internal/2002@bes2.sip.urbancom.net:5060 Action set(hangup_after_bridge=true)
  129. Dialplan: sofia/internal/2002@bes2.sip.urbancom.net:5060 Action set(effective_caller_id_name=${outbound_caller_id_name})
  130. Dialplan: sofia/internal/2002@bes2.sip.urbancom.net:5060 Action set(effective_caller_id_number=${outbound_caller_id_number})
  131. Dialplan: sofia/internal/2002@bes2.sip.urbancom.net:5060 Action set(inherit_codec=true)
  132. Dialplan: sofia/internal/2002@bes2.sip.urbancom.net:5060 Action set(ignore_display_updates=true)
  133. Dialplan: sofia/internal/2002@bes2.sip.urbancom.net:5060 Action set(callee_id_number=17085143073)
  134. Dialplan: sofia/internal/2002@bes2.sip.urbancom.net:5060 Action set(continue_on_fail=true)
  135. Dialplan: sofia/internal/2002@bes2.sip.urbancom.net:5060 Action bridge(sofia/gateway/f85a3f69-aedb-4dc1-8185-c45ad7f3ab97/17085143073)
  136. 2016-05-17 21:26:59.057791 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/2002@bes2.sip.urbancom.net:5060) State Change CS_ROUTING -> CS_EXECUTE
  137. 2016-05-17 21:26:59.057791 [DEBUG] switch_core_state_machine.c:602 (sofia/internal/2002@bes2.sip.urbancom.net:5060) State ROUTING going to sleep
  138. 2016-05-17 21:26:59.057791 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/2002@bes2.sip.urbancom.net:5060) Running State Change CS_EXECUTE
  139. 2016-05-17 21:26:59.057791 [DEBUG] switch_core_state_machine.c:609 (sofia/internal/2002@bes2.sip.urbancom.net:5060) State EXECUTE
  140. 2016-05-17 21:26:59.057791 [DEBUG] mod_sofia.c:197 sofia/internal/2002@bes2.sip.urbancom.net:5060 SOFIA EXECUTE
  141. 2016-05-17 21:26:59.057791 [DEBUG] switch_core_state_machine.c:328 sofia/internal/2002@bes2.sip.urbancom.net:5060 Standard EXECUTE
  142. EXECUTE sofia/internal/2002@bes2.sip.urbancom.net:5060 set(call_direction=local)
  143. 2016-05-17 21:26:59.057791 [DEBUG] mod_dptools.c:1519 SET sofia/internal/2002@bes2.sip.urbancom.net:5060 [call_direction]=[local]
  144. EXECUTE sofia/internal/2002@bes2.sip.urbancom.net:5060 export(origination_callee_id_name=17085143073)
  145. 2016-05-17 21:26:59.057791 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [origination_callee_id_name]=[17085143073]
  146. EXECUTE sofia/internal/2002@bes2.sip.urbancom.net:5060 set(RFC2822_DATE=Tue, 17 May 2016 21:26:59 -0500)
  147. 2016-05-17 21:26:59.057791 [DEBUG] mod_dptools.c:1519 SET sofia/internal/2002@bes2.sip.urbancom.net:5060 [RFC2822_DATE]=[Tue, 17 May 2016 21:26:59 -0500]
  148. EXECUTE sofia/internal/2002@bes2.sip.urbancom.net:5060 hash(insert/bes2.sip.urbancom.net-last_dial/2002/17085143073)
  149. EXECUTE sofia/internal/2002@bes2.sip.urbancom.net:5060 set(sip_h_X-accountcode=bes2.sip.urbancom.net)
  150. 2016-05-17 21:26:59.057791 [DEBUG] mod_dptools.c:1519 SET sofia/internal/2002@bes2.sip.urbancom.net:5060 [sip_h_X-accountcode]=[bes2.sip.urbancom.net]
  151. EXECUTE sofia/internal/2002@bes2.sip.urbancom.net:5060 set(call_direction=outbound)
  152. 2016-05-17 21:26:59.057791 [DEBUG] mod_dptools.c:1519 SET sofia/internal/2002@bes2.sip.urbancom.net:5060 [call_direction]=[outbound]
  153. EXECUTE sofia/internal/2002@bes2.sip.urbancom.net:5060 set(hangup_after_bridge=true)
  154. 2016-05-17 21:26:59.057791 [DEBUG] mod_dptools.c:1519 SET sofia/internal/2002@bes2.sip.urbancom.net:5060 [hangup_after_bridge]=[true]
  155. EXECUTE sofia/internal/2002@bes2.sip.urbancom.net:5060 set(effective_caller_id_name=Brent Desk Phone 2)
  156. 2016-05-17 21:26:59.057791 [DEBUG] mod_dptools.c:1519 SET sofia/internal/2002@bes2.sip.urbancom.net:5060 [effective_caller_id_name]=[Brent Desk Phone 2]
  157. EXECUTE sofia/internal/2002@bes2.sip.urbancom.net:5060 set(effective_caller_id_number=6303437372)
  158. 2016-05-17 21:26:59.057791 [DEBUG] mod_dptools.c:1519 SET sofia/internal/2002@bes2.sip.urbancom.net:5060 [effective_caller_id_number]=[6303437372]
  159. EXECUTE sofia/internal/2002@bes2.sip.urbancom.net:5060 set(inherit_codec=true)
  160. 2016-05-17 21:26:59.057791 [DEBUG] mod_dptools.c:1519 SET sofia/internal/2002@bes2.sip.urbancom.net:5060 [inherit_codec]=[true]
  161. EXECUTE sofia/internal/2002@bes2.sip.urbancom.net:5060 set(ignore_display_updates=true)
  162. 2016-05-17 21:26:59.057791 [DEBUG] mod_dptools.c:1519 SET sofia/internal/2002@bes2.sip.urbancom.net:5060 [ignore_display_updates]=[true]
  163. EXECUTE sofia/internal/2002@bes2.sip.urbancom.net:5060 set(callee_id_number=17085143073)
  164. 2016-05-17 21:26:59.057791 [DEBUG] mod_dptools.c:1519 SET sofia/internal/2002@bes2.sip.urbancom.net:5060 [callee_id_number]=[17085143073]
  165. EXECUTE sofia/internal/2002@bes2.sip.urbancom.net:5060 set(continue_on_fail=true)
  166. 2016-05-17 21:26:59.057791 [DEBUG] mod_dptools.c:1519 SET sofia/internal/2002@bes2.sip.urbancom.net:5060 [continue_on_fail]=[true]
  167. EXECUTE sofia/internal/2002@bes2.sip.urbancom.net:5060 bridge(sofia/gateway/f85a3f69-aedb-4dc1-8185-c45ad7f3ab97/17085143073)
  168. 2016-05-17 21:26:59.057791 [DEBUG] switch_channel.c:1250 sofia/internal/2002@bes2.sip.urbancom.net:5060 EXPORTING[export_vars] [domain_name]=[bes2.sip.urbancom.net] to event
  169. 2016-05-17 21:26:59.057791 [DEBUG] switch_channel.c:1250 sofia/internal/2002@bes2.sip.urbancom.net:5060 EXPORTING[export_vars] [origination_callee_id_name]=[17085143073] to event
  170. 2016-05-17 21:26:59.057791 [DEBUG] switch_ivr_originate.c:2127 Parsing global variables
  171. 2016-05-17 21:26:59.057791 [NOTICE] switch_channel.c:1104 New Channel sofia/external/17085143073 [accf12ad-ebfb-4c4c-84f8-717521d81cb6]
  172. 2016-05-17 21:26:59.057791 [DEBUG] mod_sofia.c:4813 (sofia/external/17085143073) State Change CS_NEW -> CS_INIT
  173. 2016-05-17 21:26:59.057791 [DEBUG] switch_core_state_machine.c:543 (sofia/external/17085143073) Running State Change CS_INIT
  174. 2016-05-17 21:26:59.057791 [DEBUG] switch_core_state_machine.c:586 (sofia/external/17085143073) State INIT
  175. 2016-05-17 21:26:59.057791 [DEBUG] mod_sofia.c:89 sofia/external/17085143073 SOFIA INIT
  176. 2016-05-17 21:26:59.057791 [DEBUG] sofia_glue.c:1257 sofia/external/17085143073 sending invite version: 1.6.8 -15-99de0ad 64bit
  177. Local SDP:
  178. v=0
  179. o=FreeSWITCH 1463518333 1463518334 IN IP4 64.7.99.51
  180. s=FreeSWITCH
  181. c=IN IP4 64.7.99.51
  182. t=0 0
  183. m=audio 20086 RTP/AVP 0 8 3 101 13
  184. a=rtpmap:0 PCMU/8000
  185. a=rtpmap:8 PCMA/8000
  186. a=rtpmap:3 GSM/8000
  187. a=rtpmap:101 telephone-event/8000
  188. a=fmtp:101 0-16
  189. a=rtpmap:13 CN/8000
  190. a=ptime:20
  191. a=sendrecv
  192.  
  193. 2016-05-17 21:26:59.057791 [DEBUG] switch_core_state_machine.c:40 sofia/external/17085143073 Standard INIT
  194. 2016-05-17 21:26:59.057791 [DEBUG] switch_core_state_machine.c:48 (sofia/external/17085143073) State Change CS_INIT -> CS_ROUTING
  195. 2016-05-17 21:26:59.057791 [DEBUG] switch_core_state_machine.c:586 (sofia/external/17085143073) State INIT going to sleep
  196. 2016-05-17 21:26:59.057791 [DEBUG] switch_core_state_machine.c:543 (sofia/external/17085143073) Running State Change CS_ROUTING
  197. 2016-05-17 21:26:59.057791 [DEBUG] switch_core_state_machine.c:602 (sofia/external/17085143073) State ROUTING
  198. 2016-05-17 21:26:59.057791 [DEBUG] mod_sofia.c:142 sofia/external/17085143073 SOFIA ROUTING
  199. 2016-05-17 21:26:59.057791 [DEBUG] switch_ivr_originate.c:67 (sofia/external/17085143073) State Change CS_ROUTING -> CS_CONSUME_MEDIA
  200. 2016-05-17 21:26:59.057791 [DEBUG] switch_core_state_machine.c:602 (sofia/external/17085143073) State ROUTING going to sleep
  201. 2016-05-17 21:26:59.057791 [DEBUG] switch_core_state_machine.c:543 (sofia/external/17085143073) Running State Change CS_CONSUME_MEDIA
  202. 2016-05-17 21:26:59.057791 [DEBUG] sofia.c:6858 Channel sofia/external/17085143073 entering state [calling][0]
  203. 2016-05-17 21:26:59.057791 [DEBUG] switch_core_state_machine.c:621 (sofia/external/17085143073) State CONSUME_MEDIA
  204. 2016-05-17 21:26:59.057791 [DEBUG] switch_core_state_machine.c:621 (sofia/external/17085143073) State CONSUME_MEDIA going to sleep
  205. 2016-05-17 21:27:00.117788 [DEBUG] sofia.c:6858 Channel sofia/external/17085143073 entering state [proceeding][183]
  206. 2016-05-17 21:27:00.117788 [DEBUG] sofia.c:6868 Remote SDP:
  207. v=0
  208. o=Sonus_UAC 588145 860659 IN IP4 67.231.1.110
  209. s=SIP Media Capabilities
  210. c=IN IP4 64.7.96.3
  211. t=0 0
  212. m=audio 59148 RTP/AVP 0 101
  213. a=rtpmap:0 PCMU/8000
  214. a=rtpmap:101 telephone-event/8000
  215. a=fmtp:101 0-15
  216. a=ptime:20
  217.  
  218. 2016-05-17 21:27:00.117788 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  219. 2016-05-17 21:27:00.117788 [DEBUG] switch_core_media.c:4410 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
  220. 2016-05-17 21:27:00.117788 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  221. 2016-05-17 21:27:00.117788 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
  222. 2016-05-17 21:27:00.117788 [DEBUG] switch_core_media.c:4271 Set telephone-event payload to 101@8000
  223. 2016-05-17 21:27:00.117788 [DEBUG] switch_core_media.c:3090 Set Codec sofia/external/17085143073 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
  224. 2016-05-17 21:27:00.117788 [DEBUG] switch_core_codec.c:111 sofia/external/17085143073 Original read codec set to PCMU:0
  225. 2016-05-17 21:27:00.117788 [DEBUG] switch_core_media.c:4623 Set telephone-event payload to 101@8000
  226. 2016-05-17 21:27:00.117788 [DEBUG] switch_core_media.c:4681 sofia/external/17085143073 Set 2833 dtmf send payload to 101 recv payload to 101
  227. 2016-05-17 21:27:00.117788 [DEBUG] switch_core_media.c:6464 AUDIO RTP [sofia/external/17085143073] 10.20.12.51 port 20086 -> 64.7.96.3 port 59148 codec: 0 ms: 20
  228. 2016-05-17 21:27:00.117788 [DEBUG] switch_rtp.c:3832 Starting timer [soft] 160 bytes per 20ms
  229. 2016-05-17 21:27:00.117788 [DEBUG] switch_core_media.c:6763 sofia/external/17085143073 Set 2833 dtmf send payload to 101
  230. 2016-05-17 21:27:00.117788 [DEBUG] switch_core_media.c:6770 sofia/external/17085143073 Set 2833 dtmf receive payload to 101
  231. 2016-05-17 21:27:00.117788 [DEBUG] switch_core_media.c:6793 sofia/external/17085143073 Set rtp dtmf delay to 40
  232. 2016-05-17 21:27:00.117788 [NOTICE] sofia_media.c:92 Pre-Answer sofia/external/17085143073!
  233. 2016-05-17 21:27:00.117788 [DEBUG] switch_channel.c:3471 (sofia/external/17085143073) Callstate Change DOWN -> EARLY
  234. 2016-05-17 21:27:00.117788 [DEBUG] switch_ivr_originate.c:410 Setting codec string on sofia/internal/2002@bes2.sip.urbancom.net:5060 to PCMU@8000h@20i
  235. 2016-05-17 21:27:00.117788 [INFO] switch_ivr_originate.c:3556 Sending early media
  236. 2016-05-17 21:27:00.117788 [DEBUG] switch_core_media.c:6464 AUDIO RTP [sofia/internal/2002@bes2.sip.urbancom.net:5060] 10.20.12.51 port 17346 -> 73.72.98.76 port 11796 codec: 0 ms: 20
  237. 2016-05-17 21:27:00.117788 [DEBUG] switch_rtp.c:3832 Starting timer [soft] 160 bytes per 20ms
  238. 2016-05-17 21:27:00.117788 [DEBUG] switch_core_media.c:6763 sofia/internal/2002@bes2.sip.urbancom.net:5060 Set 2833 dtmf send payload to 101
  239. 2016-05-17 21:27:00.117788 [DEBUG] switch_core_media.c:6770 sofia/internal/2002@bes2.sip.urbancom.net:5060 Set 2833 dtmf receive payload to 101
  240. 2016-05-17 21:27:00.117788 [DEBUG] switch_core_media.c:6793 sofia/internal/2002@bes2.sip.urbancom.net:5060 Set rtp dtmf delay to 40
  241. 2016-05-17 21:27:00.117788 [DEBUG] mod_sofia.c:2367 Ring SDP:
  242. v=0
  243. o=FreeSWITCH 1463521074 1463521075 IN IP4 64.7.99.51
  244. s=FreeSWITCH
  245. c=IN IP4 64.7.99.51
  246. t=0 0
  247. m=audio 17346 RTP/AVP 0 101
  248. a=rtpmap:0 PCMU/8000
  249. a=rtpmap:101 telephone-event/8000
  250. a=fmtp:101 0-16
  251. a=ptime:20
  252. a=sendrecv
  253. ---------------------------------------------
  254. WORKING:
  255. ---------------------------------------------
  256. 2016-05-17 23:56:26.005529 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/1002@bes1.sip.urbancom.net:5060 [cd2e3a3b-f85f-4201-92ee-376c779ff3d7]
  257. 2016-05-17 23:56:26.005529 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/1002@bes1.sip.urbancom.net:5060) Running State Change CS_NEW
  258. 2016-05-17 23:56:26.053076 [DEBUG] sofia.c:9376 sofia/internal/1002@bes1.sip.urbancom.net:5060 receiving invite from 73.72.98.76:5060 version: 1.6.8 -15-99de0ad 64bit
  259. 2016-05-17 23:56:26.085478 [DEBUG] sofia.c:9543 IP 73.72.98.76 Rejected by acl "domains". Falling back to Digest auth.
  260. 2016-05-17 23:56:26.085478 [WARNING] sofia_reg.c:1775 SIP auth challenge (INVITE) on sofia profile 'internal' for [17085143073@bes1.sip.urbancom.net] from ip 73.72.98.76
  261. 2016-05-17 23:56:26.085478 [DEBUG] switch_core_state_machine.c:562 (sofia/internal/1002@bes1.sip.urbancom.net:5060) State NEW
  262. 2016-05-17 23:56:26.085478 [DEBUG] sofia.c:2214 detaching session cd2e3a3b-f85f-4201-92ee-376c779ff3d7
  263. 2016-05-17 23:56:26.105460 [DEBUG] sofia.c:2322 Re-attaching to session cd2e3a3b-f85f-4201-92ee-376c779ff3d7
  264. 2016-05-17 23:56:26.125461 [DEBUG] sofia.c:9376 sofia/internal/1002@bes1.sip.urbancom.net:5060 receiving invite from 73.72.98.76:5060 version: 1.6.8 -15-99de0ad 64bit
  265. 2016-05-17 23:56:26.125461 [DEBUG] sofia.c:9543 IP 73.72.98.76 Rejected by acl "domains". Falling back to Digest auth.
  266. 2016-05-17 23:56:26.165470 [DEBUG] sofia.c:6858 Channel sofia/internal/1002@bes1.sip.urbancom.net:5060 entering state [received][100]
  267. 2016-05-17 23:56:26.165470 [DEBUG] sofia.c:6868 Remote SDP:
  268. v=0
  269. o=- 20000 20000 IN IP4 73.72.98.76
  270. s=SDP data
  271. c=IN IP4 73.72.98.76
  272. t=0 0
  273. m=audio 11780 RTP/AVP 0 8 18 9 101
  274. a=rtpmap:0 PCMU/8000
  275. a=rtpmap:8 PCMA/8000
  276. a=rtpmap:18 G729/8000
  277. a=fmtp:18 annexb=no
  278. a=rtpmap:9 G722/8000
  279. a=rtpmap:101 telephone-event/8000
  280. a=fmtp:101 0-15
  281. a=ptime:20
  282.  
  283. 2016-05-17 23:56:26.165470 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  284. 2016-05-17 23:56:26.165470 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  285. 2016-05-17 23:56:26.165470 [DEBUG] switch_core_media.c:4410 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
  286. 2016-05-17 23:56:26.165470 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  287. 2016-05-17 23:56:26.165470 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
  288. 2016-05-17 23:56:26.165470 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  289. 2016-05-17 23:56:26.165470 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  290. 2016-05-17 23:56:26.165470 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  291. 2016-05-17 23:56:26.165470 [DEBUG] switch_core_media.c:4410 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
  292. 2016-05-17 23:56:26.165470 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
  293. 2016-05-17 23:56:26.205465 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [G729:18:8000:20:8000:1]/[G722:9:8000:20:64000:1]
  294. 2016-05-17 23:56:26.205465 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
  295. 2016-05-17 23:56:26.205465 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
  296. 2016-05-17 23:56:26.205465 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [G729:18:8000:20:8000:1]/[GSM:3:8000:20:13200:1]
  297. 2016-05-17 23:56:26.205465 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  298. 2016-05-17 23:56:26.205465 [DEBUG] switch_core_media.c:4410 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match
  299. 2016-05-17 23:56:26.205465 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  300. 2016-05-17 23:56:26.205465 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  301. 2016-05-17 23:56:26.205465 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [G722:9:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
  302. 2016-05-17 23:56:26.205465 [DEBUG] switch_core_media.c:4271 Set telephone-event payload to 101@8000
  303. 2016-05-17 23:56:26.205465 [DEBUG] switch_core_media.c:3090 Set Codec sofia/internal/1002@bes1.sip.urbancom.net:5060 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
  304. 2016-05-17 23:56:26.205465 [DEBUG] switch_core_codec.c:111 sofia/internal/1002@bes1.sip.urbancom.net:5060 Original read codec set to PCMU:0
  305. 2016-05-17 23:56:26.205465 [DEBUG] switch_core_media.c:4623 Set telephone-event payload to 101@8000
  306. 2016-05-17 23:56:26.205465 [DEBUG] switch_core_media.c:4681 sofia/internal/1002@bes1.sip.urbancom.net:5060 Set 2833 dtmf send payload to 101 recv payload to 101
  307. 2016-05-17 23:56:26.205465 [DEBUG] sofia.c:7248 (sofia/internal/1002@bes1.sip.urbancom.net:5060) State Change CS_NEW -> CS_INIT
  308. 2016-05-17 23:56:26.205465 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/1002@bes1.sip.urbancom.net:5060) Running State Change CS_INIT
  309. 2016-05-17 23:56:26.205465 [DEBUG] switch_core_state_machine.c:586 (sofia/internal/1002@bes1.sip.urbancom.net:5060) State INIT
  310. 2016-05-17 23:56:26.205465 [DEBUG] mod_sofia.c:89 sofia/internal/1002@bes1.sip.urbancom.net:5060 SOFIA INIT
  311. 2016-05-17 23:56:26.205465 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1002@bes1.sip.urbancom.net:5060 Standard INIT
  312. 2016-05-17 23:56:26.205465 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1002@bes1.sip.urbancom.net:5060) State Change CS_INIT -> CS_ROUTING
  313. 2016-05-17 23:56:26.205465 [DEBUG] switch_core_state_machine.c:586 (sofia/internal/1002@bes1.sip.urbancom.net:5060) State INIT going to sleep
  314. 2016-05-17 23:56:26.205465 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/1002@bes1.sip.urbancom.net:5060) Running State Change CS_ROUTING
  315. 2016-05-17 23:56:26.205465 [DEBUG] switch_channel.c:2249 (sofia/internal/1002@bes1.sip.urbancom.net:5060) Callstate Change DOWN -> RINGING
  316. 2016-05-17 23:56:26.205465 [DEBUG] switch_core_state_machine.c:602 (sofia/internal/1002@bes1.sip.urbancom.net:5060) State ROUTING
  317. 2016-05-17 23:56:26.205465 [DEBUG] mod_sofia.c:142 sofia/internal/1002@bes1.sip.urbancom.net:5060 SOFIA ROUTING
  318. 2016-05-17 23:56:26.205465 [DEBUG] switch_core_state_machine.c:236 sofia/internal/1002@bes1.sip.urbancom.net:5060 Standard ROUTING
  319. 2016-05-17 23:56:26.205465 [INFO] mod_dialplan_xml.c:637 Processing 1002 <1002>->17085143073 in context bes1.sip.urbancom.net
  320. 2016-05-17 23:56:26.225469 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f7d7c02b2c0 Connected.
  321. 2016-05-17 23:56:26.315354 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f7d7c02b2c0 released.
  322. Dialplan: sofia/internal/1002@bes1.sip.urbancom.net:5060 parsing [bes1.sip.urbancom.net->user_exists] continue=true
  323. Dialplan: sofia/internal/1002@bes1.sip.urbancom.net:5060 Regex (PASS) [user_exists] () =~ // break=on-false
  324. Dialplan: sofia/internal/1002@bes1.sip.urbancom.net:5060 Action set(user_exists=${user_exists id ${destination_number} ${domain_name}}) INLINE
  325. 2016-05-17 23:56:26.315354 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f7d7c02b2c0 Connected.
  326. 2016-05-17 23:56:26.315354 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f7d7c02b2c0 released.
  327. EXECUTE sofia/internal/1002@bes1.sip.urbancom.net:5060 set(user_exists=false)
  328. 2016-05-17 23:56:26.325462 [DEBUG] mod_dptools.c:1519 SET sofia/internal/1002@bes1.sip.urbancom.net:5060 [user_exists]=[false]
  329. Dialplan: sofia/internal/1002@bes1.sip.urbancom.net:5060 Regex (FAIL) [user_exists] ${user_exists}(false) =~ /^true$/ break=on-false
  330. Dialplan: sofia/internal/1002@bes1.sip.urbancom.net:5060 parsing [bes1.sip.urbancom.net->call-direction] continue=true
  331. Dialplan: sofia/internal/1002@bes1.sip.urbancom.net:5060 Regex (FAIL) [call-direction] ${call_direction}() =~ /^(inbound|outbound|local)$/ break=never
  332. Dialplan: sofia/internal/1002@bes1.sip.urbancom.net:5060 ANTI-Action set(call_direction=local)
  333. Dialplan: sofia/internal/1002@bes1.sip.urbancom.net:5060 parsing [bes1.sip.urbancom.net->variables] continue=true
  334. Dialplan: sofia/internal/1002@bes1.sip.urbancom.net:5060 Regex (PASS) [variables] () =~ // break=on-false
  335. Dialplan: sofia/internal/1002@bes1.sip.urbancom.net:5060 Action export(origination_callee_id_name=${destination_number})
  336. Dialplan: sofia/internal/1002@bes1.sip.urbancom.net:5060 Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
  337. Dialplan: sofia/internal/1002@bes1.sip.urbancom.net:5060 parsing [bes1.sip.urbancom.net->user_record] continue=true
  338. Dialplan: sofia/internal/1002@bes1.sip.urbancom.net:5060 Regex (PASS) [user_record] () =~ // break=on-false
  339. Dialplan: sofia/internal/1002@bes1.sip.urbancom.net:5060 Action set(user_record=${user_data ${destination_number}@${domain_name} var user_record}) INLINE
  340. 2016-05-17 23:56:26.325462 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f7d7c02b2c0 Connected.
  341. 2016-05-17 23:56:26.325462 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f7d7c02b2c0 released.
  342. 2016-05-17 23:56:26.325462 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f7d7c02b2c0 Connected.
  343. 2016-05-17 23:56:26.325462 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f7d7c02b2c0 released.
  344. EXECUTE sofia/internal/1002@bes1.sip.urbancom.net:5060 set(user_record=)
  345. 2016-05-17 23:56:26.325462 [DEBUG] mod_dptools.c:1519 SET sofia/internal/1002@bes1.sip.urbancom.net:5060 [user_record]=[UNDEF]
  346. Dialplan: sofia/internal/1002@bes1.sip.urbancom.net:5060 Action set(from_user_exists=${user_exists id ${sip_from_user} ${sip_from_host}}) INLINE
  347. EXECUTE sofia/internal/1002@bes1.sip.urbancom.net:5060 set(from_user_exists=true)
  348. 2016-05-17 23:56:26.325462 [DEBUG] mod_dptools.c:1519 SET sofia/internal/1002@bes1.sip.urbancom.net:5060 [from_user_exists]=[true]
  349. Dialplan: sofia/internal/1002@bes1.sip.urbancom.net:5060 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
  350. Dialplan: sofia/internal/1002@bes1.sip.urbancom.net:5060 Regex (FAIL) [user_record] ${user_record}() =~ /^all$/ break=never
  351. Dialplan: sofia/internal/1002@bes1.sip.urbancom.net:5060 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
  352. Dialplan: sofia/internal/1002@bes1.sip.urbancom.net:5060 Regex (FAIL) [user_record] ${call_direction}() =~ /^inbound$/ break=never
  353. Dialplan: sofia/internal/1002@bes1.sip.urbancom.net:5060 Regex (FAIL) [user_record] ${user_record}() =~ /^inbound$/ break=never
  354. Dialplan: sofia/internal/1002@bes1.sip.urbancom.net:5060 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
  355. Dialplan: sofia/internal/1002@bes1.sip.urbancom.net:5060 Regex (FAIL) [user_record] ${call_direction}() =~ /^outbound$/ break=never
  356. Dialplan: sofia/internal/1002@bes1.sip.urbancom.net:5060 Regex (FAIL) [user_record] ${user_record}() =~ /^outbound$/ break=never
  357. Dialplan: sofia/internal/1002@bes1.sip.urbancom.net:5060 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
  358. Dialplan: sofia/internal/1002@bes1.sip.urbancom.net:5060 Regex (FAIL) [user_record] ${call_direction}() =~ /^local$/ break=never
  359. Dialplan: sofia/internal/1002@bes1.sip.urbancom.net:5060 Regex (FAIL) [user_record] ${user_record}() =~ /^local$/ break=never
  360. Dialplan: sofia/internal/1002@bes1.sip.urbancom.net:5060 Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
  361. Dialplan: sofia/internal/1002@bes1.sip.urbancom.net:5060 Action set(from_user_record=${user_data ${sip_from_user}@${sip_from_host} var user_record}) INLINE
  362. EXECUTE sofia/internal/1002@bes1.sip.urbancom.net:5060 set(from_user_record=)
  363. 2016-05-17 23:56:26.325462 [DEBUG] mod_dptools.c:1519 SET sofia/internal/1002@bes1.sip.urbancom.net:5060 [from_user_record]=[UNDEF]
  364. Dialplan: sofia/internal/1002@bes1.sip.urbancom.net:5060 Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
  365. Dialplan: sofia/internal/1002@bes1.sip.urbancom.net:5060 Regex (FAIL) [user_record] ${from_user_record}() =~ /^all$/ break=never
  366. Dialplan: sofia/internal/1002@bes1.sip.urbancom.net:5060 Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
  367. Dialplan: sofia/internal/1002@bes1.sip.urbancom.net:5060 Regex (FAIL) [user_record] ${call_direction}() =~ /^inbound$/ break=never
  368. Dialplan: sofia/internal/1002@bes1.sip.urbancom.net:5060 Regex (FAIL) [user_record] ${from_user_record}() =~ /^inbound$/ break=never
  369. Dialplan: sofia/internal/1002@bes1.sip.urbancom.net:5060 Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
  370. Dialplan: sofia/internal/1002@bes1.sip.urbancom.net:5060 Regex (FAIL) [user_record] ${call_direction}() =~ /^outbound$/ break=never
  371. Dialplan: sofia/internal/1002@bes1.sip.urbancom.net:5060 Regex (FAIL) [user_record] ${from_user_record}() =~ /^outbound$/ break=never
  372. Dialplan: sofia/internal/1002@bes1.sip.urbancom.net:5060 Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
  373. Dialplan: sofia/internal/1002@bes1.sip.urbancom.net:5060 Regex (FAIL) [user_record] ${call_direction}() =~ /^local$/ break=never
  374. Dialplan: sofia/internal/1002@bes1.sip.urbancom.net:5060 Regex (FAIL) [user_record] ${from_user_record}() =~ /^local$/ break=never
  375. Dialplan: sofia/internal/1002@bes1.sip.urbancom.net:5060 Regex (FAIL) [user_record] ${record_session}() =~ /^true$/ break=on-false
  376. Dialplan: sofia/internal/1002@bes1.sip.urbancom.net:5060 parsing [bes1.sip.urbancom.net->redial] continue=true
  377. Dialplan: sofia/internal/1002@bes1.sip.urbancom.net:5060 Regex (FAIL) [redial] destination_number(17085143073) =~ /^(redial|\*870)$/ break=on-true
  378. Dialplan: sofia/internal/1002@bes1.sip.urbancom.net:5060 Regex (PASS) [redial] () =~ // break=never
  379. Dialplan: sofia/internal/1002@bes1.sip.urbancom.net:5060 Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
  380. Dialplan: sofia/internal/1002@bes1.sip.urbancom.net:5060 parsing [bes1.sip.urbancom.net->sip.urbancom.net.11d] continue=false
  381. Dialplan: sofia/internal/1002@bes1.sip.urbancom.net:5060 Regex (PASS) [sip.urbancom.net.11d] destination_number(17085143073) =~ /^\+?(\d{11})$/ break=on-false
  382. Dialplan: sofia/internal/1002@bes1.sip.urbancom.net:5060 Action set(sip_h_X-accountcode=${accountcode})
  383. Dialplan: sofia/internal/1002@bes1.sip.urbancom.net:5060 Action set(call_direction=outbound)
  384. Dialplan: sofia/internal/1002@bes1.sip.urbancom.net:5060 Action set(hangup_after_bridge=true)
  385. Dialplan: sofia/internal/1002@bes1.sip.urbancom.net:5060 Action set(effective_caller_id_name=${outbound_caller_id_name})
  386. Dialplan: sofia/internal/1002@bes1.sip.urbancom.net:5060 Action set(effective_caller_id_number=${outbound_caller_id_number})
  387. Dialplan: sofia/internal/1002@bes1.sip.urbancom.net:5060 Action set(inherit_codec=true)
  388. Dialplan: sofia/internal/1002@bes1.sip.urbancom.net:5060 Action set(ignore_display_updates=true)
  389. Dialplan: sofia/internal/1002@bes1.sip.urbancom.net:5060 Action set(callee_id_number=17085143073)
  390. Dialplan: sofia/internal/1002@bes1.sip.urbancom.net:5060 Action set(continue_on_fail=true)
  391. Dialplan: sofia/internal/1002@bes1.sip.urbancom.net:5060 Action bridge(sofia/gateway/e5bf946d-fbb9-4c23-adb9-b43ed166aa0e/17085143073)
  392. 2016-05-17 23:56:26.325462 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/1002@bes1.sip.urbancom.net:5060) State Change CS_ROUTING -> CS_EXECUTE
  393. 2016-05-17 23:56:26.325462 [DEBUG] switch_core_state_machine.c:602 (sofia/internal/1002@bes1.sip.urbancom.net:5060) State ROUTING going to sleep
  394. 2016-05-17 23:56:26.325462 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/1002@bes1.sip.urbancom.net:5060) Running State Change CS_EXECUTE
  395. 2016-05-17 23:56:26.325462 [DEBUG] switch_core_state_machine.c:609 (sofia/internal/1002@bes1.sip.urbancom.net:5060) State EXECUTE
  396. 2016-05-17 23:56:26.325462 [DEBUG] mod_sofia.c:197 sofia/internal/1002@bes1.sip.urbancom.net:5060 SOFIA EXECUTE
  397. 2016-05-17 23:56:26.325462 [DEBUG] switch_core_state_machine.c:328 sofia/internal/1002@bes1.sip.urbancom.net:5060 Standard EXECUTE
  398. EXECUTE sofia/internal/1002@bes1.sip.urbancom.net:5060 set(call_direction=local)
  399. 2016-05-17 23:56:26.325462 [DEBUG] mod_dptools.c:1519 SET sofia/internal/1002@bes1.sip.urbancom.net:5060 [call_direction]=[local]
  400. EXECUTE sofia/internal/1002@bes1.sip.urbancom.net:5060 export(origination_callee_id_name=17085143073)
  401. 2016-05-17 23:56:26.325462 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [origination_callee_id_name]=[17085143073]
  402. EXECUTE sofia/internal/1002@bes1.sip.urbancom.net:5060 set(RFC2822_DATE=Tue, 17 May 2016 23:56:26 -0500)
  403. 2016-05-17 23:56:26.325462 [DEBUG] mod_dptools.c:1519 SET sofia/internal/1002@bes1.sip.urbancom.net:5060 [RFC2822_DATE]=[Tue, 17 May 2016 23:56:26 -0500]
  404. EXECUTE sofia/internal/1002@bes1.sip.urbancom.net:5060 hash(insert/bes1.sip.urbancom.net-last_dial/1002/17085143073)
  405. EXECUTE sofia/internal/1002@bes1.sip.urbancom.net:5060 set(sip_h_X-accountcode=bes1.sip.urbancom.net)
  406. 2016-05-17 23:56:26.365456 [DEBUG] mod_dptools.c:1519 SET sofia/internal/1002@bes1.sip.urbancom.net:5060 [sip_h_X-accountcode]=[bes1.sip.urbancom.net]
  407. EXECUTE sofia/internal/1002@bes1.sip.urbancom.net:5060 set(call_direction=outbound)
  408. 2016-05-17 23:56:26.365456 [DEBUG] mod_dptools.c:1519 SET sofia/internal/1002@bes1.sip.urbancom.net:5060 [call_direction]=[outbound]
  409. EXECUTE sofia/internal/1002@bes1.sip.urbancom.net:5060 set(hangup_after_bridge=true)
  410. 2016-05-17 23:56:26.365456 [DEBUG] mod_dptools.c:1519 SET sofia/internal/1002@bes1.sip.urbancom.net:5060 [hangup_after_bridge]=[true]
  411. EXECUTE sofia/internal/1002@bes1.sip.urbancom.net:5060 set(effective_caller_id_name=Brent Desk Phone)
  412. 2016-05-17 23:56:26.365456 [DEBUG] mod_dptools.c:1519 SET sofia/internal/1002@bes1.sip.urbancom.net:5060 [effective_caller_id_name]=[Brent Desk Phone]
  413. EXECUTE sofia/internal/1002@bes1.sip.urbancom.net:5060 set(effective_caller_id_number=7085871872)
  414. 2016-05-17 23:56:26.365456 [DEBUG] mod_dptools.c:1519 SET sofia/internal/1002@bes1.sip.urbancom.net:5060 [effective_caller_id_number]=[7085871872]
  415. EXECUTE sofia/internal/1002@bes1.sip.urbancom.net:5060 set(inherit_codec=true)
  416. 2016-05-17 23:56:26.365456 [DEBUG] mod_dptools.c:1519 SET sofia/internal/1002@bes1.sip.urbancom.net:5060 [inherit_codec]=[true]
  417. EXECUTE sofia/internal/1002@bes1.sip.urbancom.net:5060 set(ignore_display_updates=true)
  418. 2016-05-17 23:56:26.365456 [DEBUG] mod_dptools.c:1519 SET sofia/internal/1002@bes1.sip.urbancom.net:5060 [ignore_display_updates]=[true]
  419. EXECUTE sofia/internal/1002@bes1.sip.urbancom.net:5060 set(callee_id_number=17085143073)
  420. 2016-05-17 23:56:26.365456 [DEBUG] mod_dptools.c:1519 SET sofia/internal/1002@bes1.sip.urbancom.net:5060 [callee_id_number]=[17085143073]
  421. EXECUTE sofia/internal/1002@bes1.sip.urbancom.net:5060 set(continue_on_fail=true)
  422. 2016-05-17 23:56:26.365456 [DEBUG] mod_dptools.c:1519 SET sofia/internal/1002@bes1.sip.urbancom.net:5060 [continue_on_fail]=[true]
  423. EXECUTE sofia/internal/1002@bes1.sip.urbancom.net:5060 bridge(sofia/gateway/e5bf946d-fbb9-4c23-adb9-b43ed166aa0e/17085143073)
  424. 2016-05-17 23:56:26.365456 [DEBUG] switch_channel.c:1250 sofia/internal/1002@bes1.sip.urbancom.net:5060 EXPORTING[export_vars] [domain_name]=[bes1.sip.urbancom.net] to event
  425. 2016-05-17 23:56:26.365456 [DEBUG] switch_channel.c:1250 sofia/internal/1002@bes1.sip.urbancom.net:5060 EXPORTING[export_vars] [origination_callee_id_name]=[17085143073] to event
  426. 2016-05-17 23:56:26.365456 [DEBUG] switch_ivr_originate.c:2127 Parsing global variables
  427. 2016-05-17 23:56:26.390631 [NOTICE] switch_channel.c:1104 New Channel sofia/external/17085143073 [ba517162-3405-42bb-9602-2fddcf91350e]
  428. 2016-05-17 23:56:26.390631 [DEBUG] mod_sofia.c:4813 (sofia/external/17085143073) State Change CS_NEW -> CS_INIT
  429. 2016-05-17 23:56:26.390631 [DEBUG] switch_core_state_machine.c:543 (sofia/external/17085143073) Running State Change CS_INIT
  430. 2016-05-17 23:56:26.425448 [DEBUG] switch_core_state_machine.c:586 (sofia/external/17085143073) State INIT
  431. 2016-05-17 23:56:26.425448 [DEBUG] mod_sofia.c:89 sofia/external/17085143073 SOFIA INIT
  432. 2016-05-17 23:56:26.425448 [DEBUG] sofia_glue.c:1257 sofia/external/17085143073 sending invite version: 1.6.8 -15-99de0ad 64bit
  433. Local SDP:
  434. v=0
  435. o=FreeSWITCH 1463521424 1463521425 IN IP4 64.7.99.50
  436. s=FreeSWITCH
  437. c=IN IP4 64.7.99.50
  438. t=0 0
  439. m=audio 25962 RTP/AVP 0 8 3 101 13
  440. a=rtpmap:0 PCMU/8000
  441. a=rtpmap:8 PCMA/8000
  442. a=rtpmap:3 GSM/8000
  443. a=rtpmap:101 telephone-event/8000
  444. a=fmtp:101 0-16
  445. a=rtpmap:13 CN/8000
  446. a=ptime:20
  447. a=sendrecv
  448.  
  449. 2016-05-17 23:56:26.425448 [DEBUG] switch_core_state_machine.c:40 sofia/external/17085143073 Standard INIT
  450. 2016-05-17 23:56:26.425448 [DEBUG] switch_core_state_machine.c:48 (sofia/external/17085143073) State Change CS_INIT -> CS_ROUTING
  451. 2016-05-17 23:56:26.425448 [DEBUG] switch_core_state_machine.c:586 (sofia/external/17085143073) State INIT going to sleep
  452. 2016-05-17 23:56:26.425448 [DEBUG] switch_core_state_machine.c:543 (sofia/external/17085143073) Running State Change CS_ROUTING
  453. 2016-05-17 23:56:26.425448 [DEBUG] switch_core_state_machine.c:602 (sofia/external/17085143073) State ROUTING
  454. 2016-05-17 23:56:26.425448 [DEBUG] mod_sofia.c:142 sofia/external/17085143073 SOFIA ROUTING
  455. 2016-05-17 23:56:26.425448 [DEBUG] switch_ivr_originate.c:67 (sofia/external/17085143073) State Change CS_ROUTING -> CS_CONSUME_MEDIA
  456. 2016-05-17 23:56:26.425448 [DEBUG] switch_core_state_machine.c:602 (sofia/external/17085143073) State ROUTING going to sleep
  457. 2016-05-17 23:56:26.425448 [DEBUG] switch_core_state_machine.c:543 (sofia/external/17085143073) Running State Change CS_CONSUME_MEDIA
  458. 2016-05-17 23:56:26.425448 [DEBUG] switch_core_state_machine.c:621 (sofia/external/17085143073) State CONSUME_MEDIA
  459. 2016-05-17 23:56:26.425448 [DEBUG] switch_core_state_machine.c:621 (sofia/external/17085143073) State CONSUME_MEDIA going to sleep
  460. 2016-05-17 23:56:26.465464 [DEBUG] sofia.c:6858 Channel sofia/external/17085143073 entering state [calling][0]
  461. 2016-05-17 23:56:28.065526 [DEBUG] sofia.c:6858 Channel sofia/external/17085143073 entering state [proceeding][183]
  462. 2016-05-17 23:56:28.065526 [DEBUG] sofia.c:6868 Remote SDP:
  463. v=0
  464. o=Sonus_UAC 108080 166791 IN IP4 67.231.1.110
  465. s=SIP Media Capabilities
  466. c=IN IP4 64.7.96.3
  467. t=0 0
  468. m=audio 59516 RTP/AVP 0 101
  469. a=rtpmap:0 PCMU/8000
  470. a=rtpmap:101 telephone-event/8000
  471. a=fmtp:101 0-15
  472. a=ptime:20
  473.  
  474. 2016-05-17 23:56:28.065526 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  475. 2016-05-17 23:56:28.065526 [DEBUG] switch_core_media.c:4410 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
  476. 2016-05-17 23:56:28.065526 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  477. 2016-05-17 23:56:28.065526 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
  478. 2016-05-17 23:56:28.065526 [DEBUG] switch_core_media.c:4271 Set telephone-event payload to 101@8000
  479. 2016-05-17 23:56:28.065526 [DEBUG] switch_core_media.c:3090 Set Codec sofia/external/17085143073 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
  480. 2016-05-17 23:56:28.065526 [DEBUG] switch_core_codec.c:111 sofia/external/17085143073 Original read codec set to PCMU:0
  481. 2016-05-17 23:56:28.065526 [DEBUG] switch_core_media.c:4623 Set telephone-event payload to 101@8000
  482. 2016-05-17 23:56:28.065526 [DEBUG] switch_core_media.c:4681 sofia/external/17085143073 Set 2833 dtmf send payload to 101 recv payload to 101
  483. 2016-05-17 23:56:28.065526 [DEBUG] switch_core_media.c:6464 AUDIO RTP [sofia/external/17085143073] 10.20.12.50 port 25962 -> 64.7.96.3 port 59516 codec: 0 ms: 20
  484. 2016-05-17 23:56:28.065526 [DEBUG] switch_rtp.c:3832 Starting timer [soft] 160 bytes per 20ms
  485. 2016-05-17 23:56:28.065526 [DEBUG] switch_core_media.c:6763 sofia/external/17085143073 Set 2833 dtmf send payload to 101
  486. 2016-05-17 23:56:28.065526 [DEBUG] switch_core_media.c:6770 sofia/external/17085143073 Set 2833 dtmf receive payload to 101
  487. 2016-05-17 23:56:28.065526 [DEBUG] switch_core_media.c:6793 sofia/external/17085143073 Set rtp dtmf delay to 40
  488. 2016-05-17 23:56:28.065526 [NOTICE] sofia_media.c:92 Pre-Answer sofia/external/17085143073!
  489. 2016-05-17 23:56:28.065526 [DEBUG] switch_channel.c:3471 (sofia/external/17085143073) Callstate Change DOWN -> EARLY
  490. 2016-05-17 23:56:28.065526 [DEBUG] switch_ivr_originate.c:410 Setting codec string on sofia/internal/1002@bes1.sip.urbancom.net:5060 to PCMU@8000h@20i
  491. 2016-05-17 23:56:28.065526 [INFO] switch_ivr_originate.c:3556 Sending early media
  492. 2016-05-17 23:56:28.093782 [DEBUG] switch_core_media.c:6464 AUDIO RTP [sofia/internal/1002@bes1.sip.urbancom.net:5060] 10.20.12.50 port 19758 -> 73.72.98.76 port 11780 codec: 0 ms: 20
  493. 2016-05-17 23:56:28.093782 [DEBUG] switch_rtp.c:3832 Starting timer [soft] 160 bytes per 20ms
  494. 2016-05-17 23:56:28.093782 [DEBUG] switch_core_media.c:6763 sofia/internal/1002@bes1.sip.urbancom.net:5060 Set 2833 dtmf send payload to 101
  495. 2016-05-17 23:56:28.093782 [DEBUG] switch_core_media.c:6770 sofia/internal/1002@bes1.sip.urbancom.net:5060 Set 2833 dtmf receive payload to 101
  496. 2016-05-17 23:56:28.093782 [DEBUG] switch_core_media.c:6793 sofia/internal/1002@bes1.sip.urbancom.net:5060 Set rtp dtmf delay to 40
  497. 2016-05-17 23:56:28.093782 [DEBUG] mod_sofia.c:2367 Ring SDP:
  498. v=0
  499. o=FreeSWITCH 1463527630 1463527631 IN IP4 10.20.12.50
  500. s=FreeSWITCH
  501. c=IN IP4 10.20.12.50
  502. t=0 0
  503. m=audio 19758 RTP/AVP 0 101
  504. a=rtpmap:0 PCMU/8000
  505. a=rtpmap:101 telephone-event/8000
  506. a=fmtp:101 0-16
  507. a=ptime:20
  508. a=sendrecv
  509.