FreeSWITCH Pastebin

NEO_moh_stuck_call_issue_trace

From Akash, 5 Years ago, written in FreeSWITCH.
- view diff
URL https://pastebin.freeswitch.org/view/fad77f59
Embed
Download Paste or View Raw
  1. span style="color: cornflowerblue; font-weight: bold;"> 2019-05-22 19:11:55.910784 [NOTICE] switch_channel.c:1104 New Channel sofia/gateway1/0449131272@202.10.26.1:5060 [a6ef2390-7c71-11e9-a7fe-33f71d9eef79]
  2. 2019-05-22 19:11:55.910784 [DEBUG] switch_core_state_machine.c:584 (sofia/gateway1/0449131272@202.10.26.1:5060) Running State Change CS_NEW (Cur 5 Tot 338354)
  3. 2019-05-22 19:11:55.910784 [DEBUG] sofia.c:9873 sofia/gateway1/0449131272@202.10.26.1:5060 receiving invite from 202.10.26.1:5060 version: 1.6.20  64bit
  4. 2019-05-22 19:11:55.910784 [DEBUG] sofia.c:9989 IP 202.10.26.1 Approved by acl "default[]". Access Granted.
  5. 2019-05-22 19:11:55.910784 [DEBUG] sofia.c:7084 Channel sofia/gateway1/0449131272@202.10.26.1:5060 entering state [received][100]
  6. 2019-05-22 19:11:55.910784 [DEBUG] sofia.c:7094 Remote SDP:
  7. v=0
  8. o=- 89383072259254 89383072259254 IN IP4 202.10.26.1
  9. s=-
  10. c=IN IP4 202.10.26.1
  11. t=0 0
  12. m=audio 43506 RTP/AVP 8 0 18 101
  13. a=rtpmap:8 PCMA/8000
  14. a=rtpmap:0 PCMU/8000
  15. a=rtpmap:18 G729/8000
  16. a=fmtp:18 annexb=no
  17. a=rtpmap:101 telephone-event/8000
  18. a=ptime:20
  19.  
  20. 2019-05-22 19:11:55.910784 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  21. 2019-05-22 19:11:55.910784 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  22. 2019-05-22 19:11:55.910784 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
  23. 2019-05-22 19:11:55.910784 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G729:18:8000:20:8000:1]
  24. 2019-05-22 19:11:55.910784 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  25. 2019-05-22 19:11:55.910784 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
  26. 2019-05-22 19:11:55.910784 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  27. 2019-05-22 19:11:55.910784 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G729:18:8000:20:8000:1]
  28. 2019-05-22 19:11:55.910784 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
  29. 2019-05-22 19:11:55.910784 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
  30. 2019-05-22 19:11:55.910784 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[G729:18:8000:20:8000:1]
  31. 2019-05-22 19:11:55.910784 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [G729:18:8000:20:8000:1] ++++ is saved as a match
  32. 2019-05-22 19:11:55.910784 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 101@8000
  33. 2019-05-22 19:11:55.910784 [DEBUG] switch_core_media.c:3061 Set Codec sofia/gateway1/0449131272@202.10.26.1:5060 PCMA/8000 20 ms 160 samples 64000 bits 1 channels
  34. 2019-05-22 19:11:55.910784 [DEBUG] switch_core_codec.c:111 sofia/gateway1/0449131272@202.10.26.1:5060 Original read codec set to PCMA:8
  35. 2019-05-22 19:11:55.910784 [DEBUG] switch_core_media.c:4708 Set telephone-event payload to 101@8000
  36. 2019-05-22 19:11:55.910784 [DEBUG] switch_core_media.c:4767 sofia/gateway1/0449131272@202.10.26.1:5060 Set 2833 dtmf send payload to 101 recv payload to 101
  37. 2019-05-22 19:11:55.910784 [DEBUG] sofia.c:7507 (sofia/gateway1/0449131272@202.10.26.1:5060) State Change CS_NEW -> CS_INIT
  38. 2019-05-22 19:11:55.910784 [DEBUG] switch_core_state_machine.c:603 (sofia/gateway1/0449131272@202.10.26.1:5060) State NEW
  39. 2019-05-22 19:11:55.910784 [DEBUG] switch_core_state_machine.c:584 (sofia/gateway1/0449131272@202.10.26.1:5060) Running State Change CS_INIT (Cur 5 Tot 338354)
  40. 2019-05-22 19:11:55.910784 [DEBUG] switch_core_state_machine.c:627 (sofia/gateway1/0449131272@202.10.26.1:5060) State INIT
  41. 2019-05-22 19:11:55.910784 [DEBUG] mod_sofia.c:90 sofia/gateway1/0449131272@202.10.26.1:5060 SOFIA INIT
  42. 2019-05-22 19:11:55.910784 [DEBUG] switch_core_state_machine.c:40 sofia/gateway1/0449131272@202.10.26.1:5060 Standard INIT
  43. 2019-05-22 19:11:55.910784 [DEBUG] switch_core_state_machine.c:48 (sofia/gateway1/0449131272@202.10.26.1:5060) State Change CS_INIT -> CS_ROUTING
  44. 2019-05-22 19:11:55.910784 [DEBUG] switch_core_state_machine.c:627 (sofia/gateway1/0449131272@202.10.26.1:5060) State INIT going to sleep
  45. 2019-05-22 19:11:55.910784 [DEBUG] switch_core_state_machine.c:584 (sofia/gateway1/0449131272@202.10.26.1:5060) Running State Change CS_ROUTING (Cur 5 Tot 338354)
  46. 2019-05-22 19:11:55.910784 [DEBUG] switch_channel.c:2249 (sofia/gateway1/0449131272@202.10.26.1:5060) Callstate Change DOWN -> RINGING
  47. 2019-05-22 19:11:55.910784 [DEBUG] switch_core_state_machine.c:643 (sofia/gateway1/0449131272@202.10.26.1:5060) State ROUTING
  48. 2019-05-22 19:11:55.910784 [DEBUG] mod_sofia.c:143 sofia/gateway1/0449131272@202.10.26.1:5060 SOFIA ROUTING
  49. 2019-05-22 19:11:55.910784 [DEBUG] switch_core_state_machine.c:236 sofia/gateway1/0449131272@202.10.26.1:5060 Standard ROUTING
  50. 2019-05-22 19:11:55.910784 [INFO] mod_dialplan_xml.c:637 Processing 0449131272 <0449131272>->0283965200 in context default
  51. 2019-05-22 19:11:55.910784 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f3eb406b550 Connected.
  52. 2019-05-22 19:11:55.910784 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM system WHERE group_title IN ('global','opensips','callingcard')
  53. 2019-05-22 19:11:55.910784 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] Dialed number : 0283965200
  54. 2019-05-22 19:11:55.910784 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] Caller Id name / number  : 0449131272 / 0449131272
  55. 2019-05-22 19:11:55.910784 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [CHECK_DID] Query :SELECT A.id as id,B.id as accountid,B.number as account_code,B.did_cid_translation as did_cid_translation,A.number as  did_number,A.connectcost,A.includedseconds,A.cost,A.inc,A.extensions,A.maxchannels,A.call_type,A.city,A.province,A.init_inc,A.leg_timeout FROM dids AS A,accounts AS B WHERE A.status=0 AND B.status=0 AND B.deleted=0 AND B.id=A.accountid AND A.number ="0283965200" LIMIT 1
  56. 2019-05-22 19:11:55.910784 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] Call direction : inbound
  57. 2019-05-22 19:11:55.910784 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [IPAUTHENTICATION] Query :SELECT ip_map.*, (SELECT number FROM accounts where id=accountid AND status=0 AND deleted=0) AS account_code FROM ip_map WHERE INET_ATON("202.10.26.1") BETWEEN(INET_ATON(SUBSTRING_INDEX(`ip`, '/', 1)) & 0xffffffff ^((0x1 <<(32 -  SUBSTRING_INDEX(`ip`, '/', -1))) -1 )) AND(INET_ATON(SUBSTRING_INDEX(`ip`, '/', 1)) |((0x100000000 >> SUBSTRING_INDEX(`ip`,'/', -1)) -1))  AND "0283965200"  LIKE CONCAT(prefix,'%') ORDER BY LENGTH(prefix) DESC LIMIT 1
  58. 2019-05-22 19:11:55.910784 [NOTICE] switch_cpp.cpp:1365 [ASTPP] [Accountcode : 7335503421]
  59. 2019-05-22 19:11:55.910784 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [DOAUTHORIZATION] Query :SELECT * FROM accounts WHERE (number = "7335503421" OR id="7335503421") AND status=0 AND deleted=0 AND (expiry >= '2019-05-22 09:11:58' OR expiry = '0000-00-00 00:00:00') limit 1
  60. 2019-05-22 19:11:55.910784 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_PACKAGE_INFO] Query :SELECT * FROM packages  as P inner join package_patterns as PKGPTR on P.id = PKGPTR.package_id WHERE (patterns ='^0283965200.*' OR patterns ='^028396520.*' OR patterns ='^02839652.*' OR patterns ='^0283965.*' OR patterns ='^028396.*' OR patterns ='^02839.*' OR patterns ='^0283.*' OR patterns ='^028.*' OR patterns ='^02.*' OR patterns ='^0.*' OR patterns ='--') AND status = 0 AND pricelist_id = 1 ORDER BY LENGTH(PKGPTR.patterns) DESC LIMIT 1
  61. 2019-05-22 19:11:55.910784 [INFO] switch_cpp.cpp:1365 [ASTPP] =============== Account Information ===================
  62. 2019-05-22 19:11:55.910784 [INFO] switch_cpp.cpp:1365 [ASTPP] User id : 3
  63. 2019-05-22 19:11:55.910784 [INFO] switch_cpp.cpp:1365 [ASTPP] Account code : 7335503421
  64. 2019-05-22 19:11:55.910784 [INFO] switch_cpp.cpp:1365 [ASTPP] Balance : 10000
  65. 2019-05-22 19:11:55.910784 [INFO] switch_cpp.cpp:1365 [ASTPP] Type : 0 [0:prepaid,1:postpaid]
  66. 2019-05-22 19:11:55.910784 [INFO] switch_cpp.cpp:1365 [ASTPP] Ratecard id : 1
  67. 2019-05-22 19:11:55.910784 [INFO] switch_cpp.cpp:1365 [ASTPP] ========================================================
  68. 2019-05-22 19:11:55.910784 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_PRICELIST_INFO] Query :select * from pricelists WHERE id = 1 AND status = 0
  69. 2019-05-22 19:11:55.910784 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [CHECK_DID] Query :SELECT A.id as id,B.id as accountid,B.number as account_code,B.did_cid_translation as did_cid_translation,A.number as  did_number,A.connectcost,A.includedseconds,A.cost,A.inc,A.extensions,A.maxchannels,A.call_type,A.city,A.province,A.init_inc,A.leg_timeout FROM dids AS A,accounts AS B WHERE A.status=0 AND B.status=0 AND B.deleted=0 AND B.id=A.accountid AND A.number ="0283965200" LIMIT 1
  70. 2019-05-22 19:11:55.910784 [INFO] switch_cpp.cpp:1365 [ASTPP] =============== Rates Information ===================
  71. 2019-05-22 19:11:55.910784 [INFO] switch_cpp.cpp:1365 [ASTPP] ID : 1209
  72. 2019-05-22 19:11:55.910784 [INFO] switch_cpp.cpp:1365 [ASTPP] Connectcost : 0.00000
  73. 2019-05-22 19:11:55.910784 [INFO] switch_cpp.cpp:1365 [ASTPP] Includedseconds : 0
  74. 2019-05-22 19:11:55.910784 [INFO] switch_cpp.cpp:1365 [ASTPP] Cost : 0.00000
  75. 2019-05-22 19:11:55.910784 [INFO] switch_cpp.cpp:1365 [ASTPP] comment : 0283965200
  76. 2019-05-22 19:11:55.910784 [INFO] switch_cpp.cpp:1365 [ASTPP] Accid : 3
  77. 2019-05-22 19:11:55.910784 [INFO] switch_cpp.cpp:1365 [ASTPP] ================================================================
  78. 2019-05-22 19:11:55.910784 [INFO] switch_cpp.cpp:1365 [ASTPP] [FIND_MAXLENGTH] Call is free - assigning max length!!! :: 1000000
  79. 2019-05-22 19:11:55.910784 [INFO] switch_cpp.cpp:1365 [ASTPP] Call Max length duration : 1000000 minutes
  80. 2019-05-22 19:11:55.910784 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [DOAUTHORIZATION] Query :SELECT * FROM accounts WHERE (number = "16" OR id="16") AND status=0 AND deleted=0 AND (expiry >= '2019-05-22 09:11:58' OR expiry = '0000-00-00 00:00:00') limit 1
  81. 2019-05-22 19:11:55.910784 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_PRICELIST_INFO] Query :select * from pricelists WHERE id = 1 AND status = 0
  82. 2019-05-22 19:11:55.910784 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_RATES] Query :SELECT * FROM routes WHERE (pattern ='^0283965200.*' OR pattern ='^028396520.*' OR pattern ='^02839652.*' OR pattern ='^0283965.*' OR pattern ='^028396.*' OR pattern ='^02839.*' OR pattern ='^0283.*' OR pattern ='^028.*' OR pattern ='^02.*' OR pattern ='^0.*' OR pattern ='--') AND status = 0 AND pricelist_id = 1  ORDER BY LENGTH(pattern) DESC,cost DESC LIMIT 1
  83. 2019-05-22 19:11:55.910784 [INFO] switch_cpp.cpp:1365 [ASTPP] =============== Rates Information ===================
  84. 2019-05-22 19:11:55.910784 [INFO] switch_cpp.cpp:1365 [ASTPP] ID : 5
  85. 2019-05-22 19:11:55.910784 [INFO] switch_cpp.cpp:1365 [ASTPP] Connectcost : 0.08000
  86. 2019-05-22 19:11:55.910784 [INFO] switch_cpp.cpp:1365 [ASTPP] Includedseconds : 0
  87. 2019-05-22 19:11:55.910784 [INFO] switch_cpp.cpp:1365 [ASTPP] Cost : 0.00000
  88. 2019-05-22 19:11:55.910784 [INFO] switch_cpp.cpp:1365 [ASTPP] comment : National
  89. 2019-05-22 19:11:55.910784 [INFO] switch_cpp.cpp:1365 [ASTPP] Accid : 3
  90. 2019-05-22 19:11:55.910784 [INFO] switch_cpp.cpp:1365 [ASTPP] ================================================================
  91. 2019-05-22 19:11:55.910784 [INFO] switch_cpp.cpp:1365 [ASTPP] [FIND_MAXLENGTH] Call is free - assigning max length!!! :: 1000000
  92. 2019-05-22 19:11:55.910784 [INFO] switch_cpp.cpp:1365 [ASTPP] [userinfo] Actual CustomerInfo XML:3
  93. 2019-05-22 19:11:55.910784 [INFO] switch_cpp.cpp:1365 [ASTPP] [userinfo] Userinfo XML:3
  94. 2019-05-22 19:11:55.910784 [INFO] switch_cpp.cpp:1365 [ASTPP] [userinfo] Actual CustomerInfo XML : 3
  95. 2019-05-22 19:11:55.910784 [WARNING] switch_cpp.cpp:1365 [ASTPP] [FSXMLINBOUND] Caller ID Translation Starts
  96. 2019-05-22 19:11:55.910784 [WARNING] switch_cpp.cpp:1365 [ASTPP] [FSXMLINBOUND] Caller ID Translation Ends
  97. 2019-05-22 19:11:55.910784 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [Dialplan] Generated XML:<?xml version="1.0" encoding="UTF-8" standalone="no"?>
  98. <document type="freeswitch/xml">
  99. <section name="dialplan" description="ASTPP Dialplan">
  100. <context name="default">
  101. <extension name="0283965200">
  102. <condition field="destination_number" expression="0283965200">
  103. <action application="set" data="effective_destination_number=0283965200"/>
  104. <action application="sched_hangup" data="+60000000 normal_clearing"/>
  105. <action application="set" data="callstart=2019-05-22 09:11:58"/>
  106. <action application="set" data="hangup_after_bridge=true"/>
  107. <action application="set" data="continue_on_fail=true"/>
  108. <action application="set" data="account_id=3"/>
  109. <action application="set" data="parent_id=0"/>
  110. <action application="set" data="entity_id=3"/>
  111. <action application="set" data="call_processed=internal"/>
  112. <action application="set" data="call_direction=inbound"/>
  113. <action application="set" data="accountname=CTS 2"/>
  114. <action application="set" data="origination_rates_did=ID:1209|CODE:^.0283965200.*|DESTINATION:0283965200|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:0.00000|INC:0|INITIALBLOCK:0|RATEGROUP:0|MARKUP:0|ACCID:16"/>
  115. <action application="set" data="origination_rates=ID:5|CODE:^02.*|DESTINATION:National|CONNECTIONCOST:0.08000|INCLUDEDSECONDS:0|COST:0.00000|INC:0|INITIALBLOCK:0|RATEGROUP:1|MARKUP:0|ACCID:3"/>
  116. <action application="set" data="original_caller_id_name=0449131272"/>
  117. <action application="set" data="original_caller_id_number=0449131272"/>
  118. <action application="set" data="effective_caller_id_name=0449131272"/>
  119. <action application="set" data="effective_caller_id_number=0449131272"/>
  120. <action application="set" data="receiver_accid=16"/>
  121. <action application="set" data="calltype=SIP-DID"/>
  122. <action application="bridge" data="{sip_contact_user=0283965200}[leg_timeout=30]sofia/default/0283965200${regex(${sofia_contact(1976788220@${domain_name})}|^[^@]+(.*)|%1)}"/>
  123. <condition field="${cond(${user_data 1976788220@${domain_name} param vm-enabled} == true ? YES : NO)}" expression="^YES$">
  124. <action application="answer"/>
  125. <action application="export" data="voicemail_alternate_greet_id=0283965200"/>
  126. <action application="voicemail" data="default $${domain_name} 1976788220"/>
  127. <anti-action application="hangup" data="${originate_disposition}"/>
  128. </condition>
  129. </condition>
  130. </extension>
  131. </context>
  132. </section>
  133. </document>
  134. 2019-05-22 19:11:55.910784 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f3eb406b550 released.
  135. Dialplan: sofia/gateway1/0449131272@202.10.26.1:5060 parsing [default->0283965200] continue=false
  136. Dialplan: sofia/gateway1/0449131272@202.10.26.1:5060 Regex (PASS) [0283965200] destination_number(0283965200) =~ /0283965200/ break=on-false
  137. Dialplan: sofia/gateway1/0449131272@202.10.26.1:5060 Action set(effective_destination_number=0283965200)
  138. Dialplan: sofia/gateway1/0449131272@202.10.26.1:5060 Action sched_hangup(+60000000 normal_clearing)
  139. Dialplan: sofia/gateway1/0449131272@202.10.26.1:5060 Action set(callstart=2019-05-22 09:11:58)
  140. Dialplan: sofia/gateway1/0449131272@202.10.26.1:5060 Action set(hangup_after_bridge=true)
  141. Dialplan: sofia/gateway1/0449131272@202.10.26.1:5060 Action set(continue_on_fail=true)
  142. Dialplan: sofia/gateway1/0449131272@202.10.26.1:5060 Action set(account_id=3)
  143. Dialplan: sofia/gateway1/0449131272@202.10.26.1:5060 Action set(parent_id=0)
  144. Dialplan: sofia/gateway1/0449131272@202.10.26.1:5060 Action set(entity_id=3)
  145. Dialplan: sofia/gateway1/0449131272@202.10.26.1:5060 Action set(call_processed=internal)
  146. Dialplan: sofia/gateway1/0449131272@202.10.26.1:5060 Action set(call_direction=inbound)
  147. Dialplan: sofia/gateway1/0449131272@202.10.26.1:5060 Action set(accountname=CTS 2)
  148. Dialplan: sofia/gateway1/0449131272@202.10.26.1:5060 Action set(origination_rates_did=ID:1209|CODE:^.0283965200.*|DESTINATION:0283965200|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:0.00000|INC:0|INITIALBLOCK:0|RATEGROUP:0|MARKUP:0|ACCID:16)
  149. Dialplan: sofia/gateway1/0449131272@202.10.26.1:5060 Action set(origination_rates=ID:5|CODE:^02.*|DESTINATION:National|CONNECTIONCOST:0.08000|INCLUDEDSECONDS:0|COST:0.00000|INC:0|INITIALBLOCK:0|RATEGROUP:1|MARKUP:0|ACCID:3)
  150. Dialplan: sofia/gateway1/0449131272@202.10.26.1:5060 Action set(original_caller_id_name=0449131272)
  151. Dialplan: sofia/gateway1/0449131272@202.10.26.1:5060 Action set(original_caller_id_number=0449131272)
  152. Dialplan: sofia/gateway1/0449131272@202.10.26.1:5060 Action set(effective_caller_id_name=0449131272)
  153. Dialplan: sofia/gateway1/0449131272@202.10.26.1:5060 Action set(effective_caller_id_number=0449131272)
  154. Dialplan: sofia/gateway1/0449131272@202.10.26.1:5060 Action set(receiver_accid=16)
  155. Dialplan: sofia/gateway1/0449131272@202.10.26.1:5060 Action set(calltype=SIP-DID)
  156. Dialplan: sofia/gateway1/0449131272@202.10.26.1:5060 Action bridge({sip_contact_user=0283965200}[leg_timeout=30]sofia/default/0283965200${regex(${sofia_contact(1976788220@${domain_name})}|^[^@]+(.*)|%1)})
  157. |--- Dialplan: Processing recursive conditions level:1 [0283965200_recur_1] require-nested=TRUE
  158. |--- Dialplan: sofia/gateway1/0449131272@202.10.26.1:5060 Regex (FAIL) [0283965200_recur_1] ${cond(${user_data 1976788220@${domain_name} param vm-enabled} == true ? YES : NO)}(NO) =~ /^YES$/ break=on-false
  159. |--- Dialplan: sofia/gateway1/0449131272@202.10.26.1:5060 ANTI-Action hangup(${originate_disposition})
  160. 2019-05-22 19:11:55.930798 [DEBUG] switch_core_state_machine.c:286 (sofia/gateway1/0449131272@202.10.26.1:5060) State Change CS_ROUTING -> CS_EXECUTE
  161. 2019-05-22 19:11:55.930798 [DEBUG] switch_core_state_machine.c:643 (sofia/gateway1/0449131272@202.10.26.1:5060) State ROUTING going to sleep
  162. 2019-05-22 19:11:55.930798 [DEBUG] switch_core_state_machine.c:584 (sofia/gateway1/0449131272@202.10.26.1:5060) Running State Change CS_EXECUTE (Cur 5 Tot 338354)
  163. 2019-05-22 19:11:55.930798 [DEBUG] switch_core_state_machine.c:650 (sofia/gateway1/0449131272@202.10.26.1:5060) State EXECUTE
  164. 2019-05-22 19:11:55.930798 [DEBUG] mod_sofia.c:198 sofia/gateway1/0449131272@202.10.26.1:5060 SOFIA EXECUTE
  165. 2019-05-22 19:11:55.930798 [DEBUG] switch_core_state_machine.c:328 sofia/gateway1/0449131272@202.10.26.1:5060 Standard EXECUTE
  166. EXECUTE sofia/gateway1/0449131272@202.10.26.1:5060 set(effective_destination_number=0283965200)
  167. 2019-05-22 19:11:55.930798 [DEBUG] mod_dptools.c:1548 SET sofia/gateway1/0449131272@202.10.26.1:5060 [effective_destination_number]=[0283965200]
  168. EXECUTE sofia/gateway1/0449131272@202.10.26.1:5060 sched_hangup(+60000000 normal_clearing)
  169. 2019-05-22 19:11:55.930798 [DEBUG] switch_scheduler.c:249 Added task 148509 switch_ivr_schedule_hangup (a6ef2390-7c71-11e9-a7fe-33f71d9eef79) to run at 1618516315
  170. EXECUTE sofia/gateway1/0449131272@202.10.26.1:5060 set(callstart=2019-05-22 09:11:58)
  171. 2019-05-22 19:11:55.930798 [DEBUG] mod_dptools.c:1548 SET sofia/gateway1/0449131272@202.10.26.1:5060 [callstart]=[2019-05-22 09:11:58]
  172. EXECUTE sofia/gateway1/0449131272@202.10.26.1:5060 set(hangup_after_bridge=true)
  173. 2019-05-22 19:11:55.930798 [DEBUG] mod_dptools.c:1548 SET sofia/gateway1/0449131272@202.10.26.1:5060 [hangup_after_bridge]=[true]
  174. EXECUTE sofia/gateway1/0449131272@202.10.26.1:5060 set(continue_on_fail=true)
  175. 2019-05-22 19:11:55.930798 [DEBUG] mod_dptools.c:1548 SET sofia/gateway1/0449131272@202.10.26.1:5060 [continue_on_fail]=[true]
  176. EXECUTE sofia/gateway1/0449131272@202.10.26.1:5060 set(account_id=3)
  177. 2019-05-22 19:11:55.930798 [DEBUG] mod_dptools.c:1548 SET sofia/gateway1/0449131272@202.10.26.1:5060 [account_id]=[3]
  178. EXECUTE sofia/gateway1/0449131272@202.10.26.1:5060 set(parent_id=0)
  179. 2019-05-22 19:11:55.930798 [DEBUG] mod_dptools.c:1548 SET sofia/gateway1/0449131272@202.10.26.1:5060 [parent_id]=[0]
  180. EXECUTE sofia/gateway1/0449131272@202.10.26.1:5060 set(entity_id=3)
  181. 2019-05-22 19:11:55.930798 [DEBUG] mod_dptools.c:1548 SET sofia/gateway1/0449131272@202.10.26.1:5060 [entity_id]=[3]
  182. EXECUTE sofia/gateway1/0449131272@202.10.26.1:5060 set(call_processed=internal)
  183. 2019-05-22 19:11:55.930798 [DEBUG] mod_dptools.c:1548 SET sofia/gateway1/0449131272@202.10.26.1:5060 [call_processed]=[internal]
  184. EXECUTE sofia/gateway1/0449131272@202.10.26.1:5060 set(call_direction=inbound)
  185. 2019-05-22 19:11:55.930798 [DEBUG] mod_dptools.c:1548 SET sofia/gateway1/0449131272@202.10.26.1:5060 [call_direction]=[inbound]
  186. EXECUTE sofia/gateway1/0449131272@202.10.26.1:5060 set(accountname=CTS 2)
  187. 2019-05-22 19:11:55.930798 [DEBUG] mod_dptools.c:1548 SET sofia/gateway1/0449131272@202.10.26.1:5060 [accountname]=[CTS 2]
  188. EXECUTE sofia/gateway1/0449131272@202.10.26.1:5060 set(origination_rates_did=ID:1209|CODE:^.0283965200.*|DESTINATION:0283965200|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:0.00000|INC:0|INITIALBLOCK:0|RATEGROUP:0|MARKUP:0|ACCID:16)
  189. 2019-05-22 19:11:55.930798 [DEBUG] mod_dptools.c:1548 SET sofia/gateway1/0449131272@202.10.26.1:5060 [origination_rates_did]=[ID:1209|CODE:^.0283965200.*|DESTINATION:0283965200|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:0.00000|INC:0|INITIALBLOCK:0|RATEGROUP:0|MARKUP:0|ACCID:16]
  190. EXECUTE sofia/gateway1/0449131272@202.10.26.1:5060 set(origination_rates=ID:5|CODE:^02.*|DESTINATION:National|CONNECTIONCOST:0.08000|INCLUDEDSECONDS:0|COST:0.00000|INC:0|INITIALBLOCK:0|RATEGROUP:1|MARKUP:0|ACCID:3)
  191. 2019-05-22 19:11:55.930798 [DEBUG] mod_dptools.c:1548 SET sofia/gateway1/0449131272@202.10.26.1:5060 [origination_rates]=[ID:5|CODE:^02.*|DESTINATION:National|CONNECTIONCOST:0.08000|INCLUDEDSECONDS:0|COST:0.00000|INC:0|INITIALBLOCK:0|RATEGROUP:1|MARKUP:0|ACCID:3]
  192. EXECUTE sofia/gateway1/0449131272@202.10.26.1:5060 set(original_caller_id_name=0449131272)
  193. 2019-05-22 19:11:55.930798 [DEBUG] mod_dptools.c:1548 SET sofia/gateway1/0449131272@202.10.26.1:5060 [original_caller_id_name]=[0449131272]
  194. EXECUTE sofia/gateway1/0449131272@202.10.26.1:5060 set(original_caller_id_number=0449131272)
  195. 2019-05-22 19:11:55.930798 [DEBUG] mod_dptools.c:1548 SET sofia/gateway1/0449131272@202.10.26.1:5060 [original_caller_id_number]=[0449131272]
  196. EXECUTE sofia/gateway1/0449131272@202.10.26.1:5060 set(effective_caller_id_name=0449131272)
  197. 2019-05-22 19:11:55.930798 [DEBUG] mod_dptools.c:1548 SET sofia/gateway1/0449131272@202.10.26.1:5060 [effective_caller_id_name]=[0449131272]
  198. EXECUTE sofia/gateway1/0449131272@202.10.26.1:5060 set(effective_caller_id_number=0449131272)
  199. 2019-05-22 19:11:55.930798 [DEBUG] mod_dptools.c:1548 SET sofia/gateway1/0449131272@202.10.26.1:5060 [effective_caller_id_number]=[0449131272]
  200. EXECUTE sofia/gateway1/0449131272@202.10.26.1:5060 set(receiver_accid=16)
  201. 2019-05-22 19:11:55.930798 [DEBUG] mod_dptools.c:1548 SET sofia/gateway1/0449131272@202.10.26.1:5060 [receiver_accid]=[16]
  202. EXECUTE sofia/gateway1/0449131272@202.10.26.1:5060 set(calltype=SIP-DID)
  203. 2019-05-22 19:11:55.930798 [DEBUG] mod_dptools.c:1548 SET sofia/gateway1/0449131272@202.10.26.1:5060 [calltype]=[SIP-DID]
  204. EXECUTE sofia/gateway1/0449131272@202.10.26.1:5060 bridge({sip_contact_user=0283965200}[leg_timeout=30]sofia/default/0283965200@58.96.28.252:5060;transport=UDP)
  205. 2019-05-22 19:11:55.930798 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
  206. 2019-05-22 19:11:55.930798 [DEBUG] switch_ivr_originate.c:2669 Parsing session specific variables
  207. 2019-05-22 19:11:55.930798 [NOTICE] switch_channel.c:1104 New Channel sofia/default/0283965200@58.96.28.252:5060 [a6f3d052-7c71-11e9-a818-33f71d9eef79]
  208. 2019-05-22 19:11:55.930798 [DEBUG] mod_sofia.c:4819 (sofia/default/0283965200@58.96.28.252:5060) State Change CS_NEW -> CS_INIT
  209. 2019-05-22 19:11:55.930798 [DEBUG] switch_ivr_originate.c:2963 sofia/default/0283965200@58.96.28.252:5060 Setting leg timeout to 30
  210. 2019-05-22 19:11:55.930798 [DEBUG] switch_core_state_machine.c:584 (sofia/default/0283965200@58.96.28.252:5060) Running State Change CS_INIT (Cur 6 Tot 338355)
  211. 2019-05-22 19:11:55.930798 [DEBUG] switch_core_state_machine.c:627 (sofia/default/0283965200@58.96.28.252:5060) State INIT
  212. 2019-05-22 19:11:55.930798 [DEBUG] mod_sofia.c:90 sofia/default/0283965200@58.96.28.252:5060 SOFIA INIT
  213. 2019-05-22 19:11:55.930798 [DEBUG] sofia_glue.c:1295 sofia/default/0283965200@58.96.28.252:5060 sending invite version: 1.6.20  64bit
  214. Local SDP:
  215. v=0
  216. o=FreeSWITCH 1558492093 1558492094 IN IP4 59.100.179.100
  217. s=FreeSWITCH
  218. c=IN IP4 59.100.179.100
  219. t=0 0
  220. m=audio 24222 RTP/AVP 8 101
  221. a=rtpmap:8 PCMA/8000
  222. a=rtpmap:101 telephone-event/8000
  223. a=fmtp:101 0-16
  224. a=ptime:20
  225. a=sendrecv
  226.  
  227. 2019-05-22 19:11:55.930798 [DEBUG] switch_core_state_machine.c:40 sofia/default/0283965200@58.96.28.252:5060 Standard INIT
  228. 2019-05-22 19:11:55.930798 [DEBUG] switch_core_state_machine.c:48 (sofia/default/0283965200@58.96.28.252:5060) State Change CS_INIT -> CS_ROUTING
  229. 2019-05-22 19:11:55.930798 [DEBUG] switch_core_state_machine.c:627 (sofia/default/0283965200@58.96.28.252:5060) State INIT going to sleep
  230. 2019-05-22 19:11:55.930798 [DEBUG] switch_core_state_machine.c:584 (sofia/default/0283965200@58.96.28.252:5060) Running State Change CS_ROUTING (Cur 6 Tot 338355)
  231. 2019-05-22 19:11:55.930798 [DEBUG] switch_core_state_machine.c:643 (sofia/default/0283965200@58.96.28.252:5060) State ROUTING
  232. 2019-05-22 19:11:55.930798 [DEBUG] mod_sofia.c:143 sofia/default/0283965200@58.96.28.252:5060 SOFIA ROUTING
  233. 2019-05-22 19:11:55.930798 [DEBUG] switch_ivr_originate.c:67 (sofia/default/0283965200@58.96.28.252:5060) State Change CS_ROUTING -> CS_CONSUME_MEDIA
  234. 2019-05-22 19:11:55.930798 [DEBUG] switch_core_state_machine.c:643 (sofia/default/0283965200@58.96.28.252:5060) State ROUTING going to sleep
  235. 2019-05-22 19:11:55.930798 [DEBUG] switch_core_state_machine.c:584 (sofia/default/0283965200@58.96.28.252:5060) Running State Change CS_CONSUME_MEDIA (Cur 6 Tot 338355)
  236. 2019-05-22 19:11:55.930798 [DEBUG] sofia.c:7084 Channel sofia/default/0283965200@58.96.28.252:5060 entering state [calling][0]
  237. 2019-05-22 19:11:55.930798 [DEBUG] switch_core_state_machine.c:662 (sofia/default/0283965200@58.96.28.252:5060) State CONSUME_MEDIA
  238. 2019-05-22 19:11:55.930798 [DEBUG] switch_core_state_machine.c:662 (sofia/default/0283965200@58.96.28.252:5060) State CONSUME_MEDIA going to sleep
  239. 2019-05-22 19:11:56.230755 [DEBUG] sofia.c:7084 Channel sofia/default/0283965200@58.96.28.252:5060 entering state [proceeding][183]
  240. 2019-05-22 19:11:56.230755 [DEBUG] sofia.c:7094 Remote SDP:
  241. v=0
  242. o=SBC 1399 1001 IN IP4 58.96.28.252
  243. s=VoipCall
  244. c=IN IP4 58.96.28.252
  245. t=0 0
  246. m=audio 16676 RTP/AVP 8 101
  247. c=IN IP4 58.96.28.252
  248. a=rtpmap:8 PCMA/8000
  249. a=rtpmap:101 telephone-event/8000
  250. a=fmtp:101 0-15
  251. a=ptime:20
  252. a=maxptime:40
  253. a=rtcp:16677
  254.  
  255. 2019-05-22 19:11:56.230755 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  256. 2019-05-22 19:11:56.230755 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
  257. 2019-05-22 19:11:56.230755 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 101@8000
  258. 2019-05-22 19:11:56.230755 [DEBUG] switch_core_media.c:3061 Set Codec sofia/default/0283965200@58.96.28.252:5060 PCMA/8000 20 ms 160 samples 64000 bits 1 channels
  259. 2019-05-22 19:11:56.230755 [DEBUG] switch_core_codec.c:111 sofia/default/0283965200@58.96.28.252:5060 Original read codec set to PCMA:8
  260. 2019-05-22 19:11:56.230755 [DEBUG] switch_core_media.c:4708 Set telephone-event payload to 101@8000
  261. 2019-05-22 19:11:56.230755 [DEBUG] switch_core_media.c:4767 sofia/default/0283965200@58.96.28.252:5060 Set 2833 dtmf send payload to 101 recv payload to 101
  262. 2019-05-22 19:11:56.230755 [DEBUG] switch_core_media.c:6878 AUDIO RTP [sofia/default/0283965200@58.96.28.252:5060] 192.168.2.210 port 24222 -> 58.96.28.252 port 16676 codec: 8 ms: 20
  263. 2019-05-22 19:11:56.230755 [DEBUG] switch_rtp.c:4137 Starting timer [soft] 160 bytes per 20ms
  264. 2019-05-22 19:11:56.250767 [DEBUG] switch_core_media.c:7096 Activating RTCP PORT 16677
  265. 2019-05-22 19:11:56.250767 [DEBUG] switch_rtp.c:4533 RTCP send rate is: 1000 and packet rate is: 20000 Remote Port: 16677
  266. 2019-05-22 19:11:56.250767 [DEBUG] switch_rtp.c:2567 Setting RTCP remote addr to 58.96.28.252:16677 2
  267. 2019-05-22 19:11:56.250767 [DEBUG] switch_core_media.c:7180 sofia/default/0283965200@58.96.28.252:5060 Set 2833 dtmf send payload to 101
  268. 2019-05-22 19:11:56.250767 [DEBUG] switch_core_media.c:7187 sofia/default/0283965200@58.96.28.252:5060 Set 2833 dtmf receive payload to 101
  269. 2019-05-22 19:11:56.250767 [DEBUG] switch_core_media.c:7210 sofia/default/0283965200@58.96.28.252:5060 Set rtp dtmf delay to 40
  270. 2019-05-22 19:11:56.250767 [NOTICE] sofia_media.c:92 Pre-Answer sofia/default/0283965200@58.96.28.252:5060!
  271. 2019-05-22 19:11:56.250767 [DEBUG] switch_channel.c:3474 (sofia/default/0283965200@58.96.28.252:5060) Callstate Change DOWN -> EARLY
  272. 2019-05-22 19:11:56.250767 [INFO] switch_ivr_originate.c:3654 Sending early media
  273. 2019-05-22 19:11:56.250767 [DEBUG] switch_core_media.c:6878 AUDIO RTP [sofia/gateway1/0449131272@202.10.26.1:5060] 10.239.237.34 port 23138 -> 202.10.26.1 port 43506 codec: 8 ms: 20
  274. 2019-05-22 19:11:56.250767 [DEBUG] switch_rtp.c:4159 Not using a timer
  275. 2019-05-22 19:11:56.250767 [DEBUG] switch_core_media.c:7180 sofia/gateway1/0449131272@202.10.26.1:5060 Set 2833 dtmf send payload to 101
  276. 2019-05-22 19:11:56.250767 [DEBUG] switch_core_media.c:7187 sofia/gateway1/0449131272@202.10.26.1:5060 Set 2833 dtmf receive payload to 101
  277. 2019-05-22 19:11:56.250767 [DEBUG] switch_core_media.c:7210 sofia/gateway1/0449131272@202.10.26.1:5060 Set rtp dtmf delay to 40
  278. 2019-05-22 19:11:56.250767 [DEBUG] mod_sofia.c:2364 Ring SDP:
  279. v=0
  280. o=FreeSWITCH 1558493178 1558493179 IN IP4 10.239.237.34
  281. s=FreeSWITCH
  282. c=IN IP4 10.239.237.34
  283. t=0 0
  284. m=audio 23138 RTP/AVP 8 101
  285. a=rtpmap:8 PCMA/8000
  286. a=rtpmap:101 telephone-event/8000
  287. a=fmtp:101 0-16
  288. a=ptime:20
  289. a=sendrecv
  290.  
  291. 2019-05-22 19:11:56.250767 [NOTICE] mod_sofia.c:2367 Pre-Answer sofia/gateway1/0449131272@202.10.26.1:5060!
  292. 2019-05-22 19:11:56.250767 [DEBUG] switch_channel.c:3474 (sofia/gateway1/0449131272@202.10.26.1:5060) Callstate Change RINGING -> EARLY
  293. 2019-05-22 19:11:56.250767 [DEBUG] switch_ivr_originate.c:3705 Originate Resulted in Success: [sofia/default/0283965200@58.96.28.252:5060]
  294. 2019-05-22 19:11:56.250767 [DEBUG] sofia.c:7084 Channel sofia/gateway1/0449131272@202.10.26.1:5060 entering state [early][183]
  295. 2019-05-22 19:11:56.250767 [DEBUG] switch_ivr_bridge.c:1614 (sofia/default/0283965200@58.96.28.252:5060) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
  296. 2019-05-22 19:11:56.250767 [DEBUG] switch_core_state_machine.c:584 (sofia/default/0283965200@58.96.28.252:5060) Running State Change CS_EXCHANGE_MEDIA (Cur 6 Tot 338355)
  297. 2019-05-22 19:11:56.250767 [DEBUG] switch_core_state_machine.c:653 (sofia/default/0283965200@58.96.28.252:5060) State EXCHANGE_MEDIA
  298. 2019-05-22 19:11:56.250767 [DEBUG] mod_sofia.c:631 SOFIA EXCHANGE_MEDIA
  299. 2019-05-22 19:11:56.330746 [DEBUG] switch_rtp.c:7308 Correct audio ip/port confirmed.
  300. 2019-05-22 19:11:56.350747 [DEBUG] switch_rtp.c:1887 rtcp_stats_init: audio ssrc[4170685508] base_seq[45584]
  301. 2019-05-22 19:11:56.510748 [DEBUG] sofia.c:7084 Channel sofia/default/0283965200@58.96.28.252:5060 entering state [proceeding][180]
  302. 2019-05-22 19:11:56.510748 [NOTICE] sofia.c:7192 Ring-Ready sofia/default/0283965200@58.96.28.252:5060!
  303. 2019-05-22 19:11:56.510748 [DEBUG] switch_channel.c:3346 (sofia/default/0283965200@58.96.28.252:5060) Callstate Change EARLY -> RINGING
  304. 2019-05-22 19:11:56.610748 [DEBUG] switch_rtp.c:7308 Correct audio ip/port confirmed.
  305. 2019-05-22 19:11:56.750750 [DEBUG] sofia.c:7084 Channel sofia/default/0283965200@58.96.28.252:5060 entering state [completing][200]
  306. 2019-05-22 19:11:56.750750 [DEBUG] sofia.c:7091 Duplicate SDP
  307. v=0
  308. o=SBC 1399 1001 IN IP4 58.96.28.252
  309. s=VoipCall
  310. c=IN IP4 58.96.28.252
  311. t=0 0
  312. m=audio 16676 RTP/AVP 8 101
  313. c=IN IP4 58.96.28.252
  314. a=rtpmap:8 PCMA/8000
  315. a=rtpmap:101 telephone-event/8000
  316. a=fmtp:101 0-15
  317. a=ptime:20
  318. a=maxptime:40
  319. a=rtcp:16677
  320.  
  321. 2019-05-22 19:11:56.770755 [DEBUG] sofia.c:7084 Channel sofia/gateway1/0499080933 entering state [completing][200]
  322. 2019-05-22 19:11:56.770755 [DEBUG] sofia.c:7091 Duplicate SDP
  323. v=0
  324. o=- 90353734859613 90353734859613 IN IP4 202.10.26.1
  325. s=-
  326. c=IN IP4 202.10.26.1
  327. t=0 0
  328. m=audio 43396 RTP/AVP 8 101
  329. a=rtpmap:8 PCMA/8000
  330. a=rtpmap:101 telephone-event/8000
  331. a=fmtp:101 0-16
  332. a=ptime:20
  333.  
  334. 2019-05-22 19:11:56.770755 [DEBUG] sofia.c:7084 Channel sofia/gateway1/0499080933 entering state [ready][200]
  335. 2019-05-22 19:11:56.770755 [NOTICE] sofia.c:8159 Channel [sofia/gateway1/0499080933] has been answered
  336. 2019-05-22 19:11:56.770755 [DEBUG] sofia.c:7084 Channel sofia/default/0283965200@58.96.28.252:5060 entering state [ready][200]
  337. 2019-05-22 19:11:56.770755 [DEBUG] switch_channel.c:3773 (sofia/gateway1/0499080933) Callstate Change EARLY -> ACTIVE
  338. 2019-05-22 19:11:56.770755 [NOTICE] sofia.c:8159 Channel [sofia/default/0283965200@58.96.28.252:5060] has been answered
  339. 2019-05-22 19:11:56.770755 [DEBUG] switch_channel.c:3773 (sofia/default/0283965200@58.96.28.252:5060) Callstate Change RINGING -> ACTIVE
  340. 2019-05-22 19:11:56.790752 [DEBUG] switch_core_media.c:6861 Audio params are unchanged for sofia/default/0731589144@192.168.2.210.
  341. 2019-05-22 19:11:56.790752 [DEBUG] mod_sofia.c:850 Local SDP sofia/default/0731589144@192.168.2.210:
  342. v=0
  343. o=FreeSWITCH 1558493939 1558493941 IN IP4 192.168.2.210
  344. s=FreeSWITCH
  345. c=IN IP4 192.168.2.210
  346. t=0 0
  347. m=audio 22368 RTP/AVP 8 101
  348. a=rtpmap:8 PCMA/8000
  349. a=rtpmap:101 telephone-event/8000
  350. a=fmtp:101 0-16
  351. a=ptime:20
  352. a=sendrecv
  353.  
  354. 2019-05-22 19:11:56.790752 [NOTICE] switch_ivr_bridge.c:623 Channel [sofia/default/0731589144@192.168.2.210] has been answered
  355. 2019-05-22 19:11:56.790752 [DEBUG] switch_channel.c:3773 (sofia/default/0731589144@192.168.2.210) Callstate Change EARLY -> ACTIVE
  356. 2019-05-22 19:11:56.790752 [DEBUG] sofia.c:7084 Channel sofia/default/0731589144@192.168.2.210 entering state [completed][200]
  357. 2019-05-22 19:11:56.790752 [DEBUG] sofia.c:7084 Channel sofia/default/0731589144@192.168.2.210 entering state [ready][200]
  358. 2019-05-22 19:11:56.790752 [DEBUG] switch_core_media.c:6861 Audio params are unchanged for sofia/gateway1/0449131272@202.10.26.1:5060.
  359. 2019-05-22 19:11:56.790752 [DEBUG] mod_sofia.c:850 Local SDP sofia/gateway1/0449131272@202.10.26.1:5060:
  360. v=0
  361. o=FreeSWITCH 1558493178 1558493180 IN IP4 10.239.237.34
  362. s=FreeSWITCH
  363. c=IN IP4 10.239.237.34
  364. t=0 0
  365. m=audio 23138 RTP/AVP 8 101
  366. a=rtpmap:8 PCMA/8000
  367. a=rtpmap:101 telephone-event/8000
  368. a=fmtp:101 0-16
  369. a=ptime:20
  370. a=sendrecv
  371.  
  372. 2019-05-22 19:11:56.790752 [NOTICE] switch_ivr_bridge.c:623 Channel [sofia/gateway1/0449131272@202.10.26.1:5060] has been answered
  373. 2019-05-22 19:11:56.790752 [DEBUG] switch_channel.c:3773 (sofia/gateway1/0449131272@202.10.26.1:5060) Callstate Change EARLY -> ACTIVE
  374. 2019-05-22 19:11:56.790752 [DEBUG] sofia.c:7084 Channel sofia/gateway1/0449131272@202.10.26.1:5060 entering state [completed][200]
  375. 2019-05-22 19:11:56.830758 [DEBUG] sofia.c:7084 Channel sofia/gateway1/0449131272@202.10.26.1:5060 entering state [ready][200]
  376. 2019-05-22 19:11:56.830758 [DEBUG] switch_rtp.c:7308 Correct audio ip/port confirmed.
  377. 2019-05-22 19:11:56.870749 [DEBUG] switch_rtp.c:7308 Correct audio ip/port confirmed.
  378. 2019-05-22 19:11:56.870749 [DEBUG] switch_rtp.c:7308 Correct audio ip/port confirmed.
  379. 2019-05-22 19:12:01.150735 [DEBUG] switch_rtp.c:7308 Correct audio ip/port confirmed.
  380. 2019-05-22 19:12:11.350750 [DEBUG] sofia.c:7084 Channel sofia/default/0283965200@58.96.28.252:5060 entering state [received][100]
  381. 2019-05-22 19:12:11.350750 [DEBUG] sofia.c:7094 Remote SDP:
  382. v=0
  383. o=SBC 1399 1002 IN IP4 58.96.28.252
  384. s=VoipCall
  385. c=IN IP4 58.96.28.252
  386. t=0 0
  387. m=audio 16676 RTP/AVP 8 101 13
  388. c=IN IP4 58.96.28.252
  389. a=rtpmap:8 PCMA/8000
  390. a=rtpmap:101 telephone-event/8000
  391. a=fmtp:101 0-15
  392. a=rtpmap:13 CN/8000
  393. a=inactive
  394. a=ptime:20
  395. a=maxptime:40
  396. a=rtcp:16677
  397.  
  398. 2019-05-22 19:12:11.350750 [DEBUG] switch_channel.c:1844 (sofia/default/0283965200@58.96.28.252:5060) Callstate Change ACTIVE -> HELD
  399. 2019-05-22 19:12:11.610733 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  400. 2019-05-22 19:12:11.610733 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
  401. 2019-05-22 19:12:11.610733 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 101@8000
  402. 2019-05-22 19:12:11.610733 [DEBUG] switch_core_media.c:4373 Set comfort noise payload to 13
  403. 2019-05-22 19:12:11.610733 [DEBUG] switch_core_media.c:4708 Set telephone-event payload to 101@8000
  404. 2019-05-22 19:12:11.610733 [DEBUG] switch_core_media.c:4720 Set comfort noise payload to 13@8000
  405. 2019-05-22 19:12:11.610733 [DEBUG] switch_core_media.c:4767 sofia/default/0283965200@58.96.28.252:5060 Set 2833 dtmf send payload to 101 recv payload to 101
  406. 2019-05-22 19:12:11.610733 [DEBUG] switch_core_media.c:6861 Audio params are unchanged for sofia/default/0283965200@58.96.28.252:5060.
  407. 2019-05-22 19:12:11.610733 [DEBUG] sofia.c:7999 Processing updated SDP
  408. 2019-05-22 19:12:11.630749 [DEBUG] sofia.c:7084 Channel sofia/default/0283965200@58.96.28.252:5060 entering state [completed][200]
  409. 2019-05-22 19:12:11.630749 [DEBUG] sofia.c:7084 Channel sofia/default/0283965200@58.96.28.252:5060 entering state [ready][200]
  410. 2019-05-22 19:12:11.650741 [DEBUG] sofia.c:7084 Channel sofia/default/0283965200@58.96.28.252:5060 entering state [received][100]
  411. 2019-05-22 19:12:11.650741 [DEBUG] sofia.c:7094 Remote SDP:
  412. v=0
  413. o=SBC 1399 1003 IN IP4 58.96.28.252
  414. s=VoipCall
  415. c=IN IP4 58.96.28.252
  416. t=0 0
  417. m=audio 16676 RTP/AVP 8 101
  418. c=IN IP4 58.96.28.252
  419. a=rtpmap:8 PCMA/8000
  420. a=rtpmap:101 telephone-event/8000
  421. a=fmtp:101 0-15
  422. a=ptime:20
  423. a=maxptime:40
  424. a=rtcp:16677
  425.  
  426. 2019-05-22 19:12:11.910744 [DEBUG] switch_channel.c:2029 (sofia/default/0283965200@58.96.28.252:5060) Callstate Change HELD -> UNHELD
  427. 2019-05-22 19:12:11.910744 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  428. 2019-05-22 19:12:11.910744 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
  429. 2019-05-22 19:12:11.910744 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 101@8000
  430. 2019-05-22 19:12:11.910744 [DEBUG] switch_core_media.c:4708 Set telephone-event payload to 101@8000
  431. 2019-05-22 19:12:11.910744 [DEBUG] switch_core_media.c:4767 sofia/default/0283965200@58.96.28.252:5060 Set 2833 dtmf send payload to 101 recv payload to 101
  432. 2019-05-22 19:12:11.910744 [DEBUG] switch_core_media.c:6861 Audio params are unchanged for sofia/default/0283965200@58.96.28.252:5060.
  433. 2019-05-22 19:12:11.910744 [DEBUG] sofia.c:7999 Processing updated SDP
  434. 2019-05-22 19:12:11.910744 [DEBUG] switch_core_io.c:941 (sofia/default/0283965200@58.96.28.252:5060) Callstate Change UNHELD -> ACTIVE
  435. 2019-05-22 19:12:11.910744 [DEBUG] sofia.c:7084 Channel sofia/default/0283965200@58.96.28.252:5060 entering state [completed][200]
  436. 2019-05-22 19:12:11.910744 [DEBUG] sofia.c:7084 Channel sofia/default/0283965200@58.96.28.252:5060 entering state [ready][200]
  437. 2019-05-22 19:12:13.090745 [DEBUG] switch_ivr.c:623 sofia/gateway1/0449131272@202.10.26.1:5060 Command Execute playback(local_stream://moh)
  438. EXECUTE sofia/gateway1/0449131272@202.10.26.1:5060 playback(local_stream://moh)
  439. 2019-05-22 19:12:13.090745 [DEBUG] mod_local_stream.c:871 Opening Stream [moh/8000] 8000hz
  440. 2019-05-22 19:12:13.090745 [DEBUG] switch_ivr_play_say.c:1498 Codec Activated L16@8000hz 1 channels 20ms
  441. 2019-05-22 19:12:35.590742 [NOTICE] sofia.c:1012 Hangup sofia/default/0283965200@58.96.28.252:5060 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING]
  442. 2019-05-22 19:12:35.590742 [DEBUG] switch_ivr_bridge.c:787 BRIDGE THREAD DONE [sofia/default/0283965200@58.96.28.252:5060]
  443. 2019-05-22 19:12:35.590742 [DEBUG] switch_core_state_machine.c:653 (sofia/default/0283965200@58.96.28.252:5060) State EXCHANGE_MEDIA going to sleep
  444. 2019-05-22 19:12:35.590742 [DEBUG] switch_core_state_machine.c:584 (sofia/default/0283965200@58.96.28.252:5060) Running State Change CS_HANGUP (Cur 6 Tot 338355)
  445. 2019-05-22 19:12:35.590742 [DEBUG] switch_core_state_machine.c:850 (sofia/default/0283965200@58.96.28.252:5060) Callstate Change ACTIVE -> HANGUP
  446. 2019-05-22 19:12:35.610746 [DEBUG] switch_core_state_machine.c:852 (sofia/default/0283965200@58.96.28.252:5060) State HANGUP
  447. 2019-05-22 19:12:35.610746 [DEBUG] mod_sofia.c:438 Channel sofia/default/0283965200@58.96.28.252:5060 hanging up, cause: NORMAL_CLEARING
  448. 2019-05-22 19:12:35.610746 [DEBUG] switch_core_state_machine.c:60 sofia/default/0283965200@58.96.28.252:5060 Standard HANGUP, cause: NORMAL_CLEARING
  449. 2019-05-22 19:12:35.610746 [DEBUG] switch_core_state_machine.c:852 (sofia/default/0283965200@58.96.28.252:5060) State HANGUP going to sleep
  450. 2019-05-22 19:12:35.610746 [DEBUG] switch_core_state_machine.c:619 (sofia/default/0283965200@58.96.28.252:5060) State Change CS_HANGUP -> CS_REPORTING
  451. 2019-05-22 19:12:35.610746 [DEBUG] switch_core_state_machine.c:584 (sofia/default/0283965200@58.96.28.252:5060) Running State Change CS_REPORTING (Cur 6 Tot 338355)
  452. 2019-05-22 19:12:35.610746 [DEBUG] switch_core_state_machine.c:938 (sofia/default/0283965200@58.96.28.252:5060) State REPORTING
  453. 2019-05-22 19:12:35.610746 [INFO] mod_json_cdr.c:271 Process [a6f3d052-7c71-11e9-a818-33f71d9eef79.cdr.json]
  454. 2019-05-22 19:12:35.610746 [DEBUG] switch_core_state_machine.c:174 sofia/default/0283965200@58.96.28.252:5060 Standard REPORTING, cause: NORMAL_CLEARING
  455. 2019-05-22 19:12:35.610746 [DEBUG] switch_core_state_machine.c:938 (sofia/default/0283965200@58.96.28.252:5060) State REPORTING going to sleep
  456. 2019-05-22 19:12:35.610746 [DEBUG] switch_core_state_machine.c:610 (sofia/default/0283965200@58.96.28.252:5060) State Change CS_REPORTING -> CS_DESTROY
  457. 2019-05-22 19:12:35.610746 [DEBUG] switch_core_session.c:1665 Session 338355 (sofia/default/0283965200@58.96.28.252:5060) Locked, Waiting on external entities

Reply to "NEO_moh_stuck_call_issue_trace"