From Fax working on old, 6 Years ago, written in FreeSWITCH.
- view diff
Embed
  1. span style="color: cornflowerblue; font-weight: bold;"> freeswitch@internal> 2018-07-04 20:43:46.391945 [NOTICE] switch_channel.c:1075 New Channel sofia/default/7120041412@103.226.53.10 [20dd777c-7f77-11e8-894d-555946780031]
  2. 2018-07-04 20:43:46.391945 [DEBUG] switch_core_session.c:1061 Send signal sofia/default/7120041412@103.226.53.10 [BREAK]
  3. 2018-07-04 20:43:46.391945 [DEBUG] switch_core_session.c:1061 Send signal sofia/default/7120041412@103.226.53.10 [BREAK]
  4. 2018-07-04 20:43:46.391945 [DEBUG] switch_core_state_machine.c:472 (sofia/default/7120041412@103.226.53.10) Running State Change CS_NEW
  5. 2018-07-04 20:43:46.391945 [DEBUG] sofia.c:8919 sofia/default/7120041412@103.226.53.10 receiving invite from 103.239.77.180:1126 version: 1.4.21  64bit
  6. 2018-07-04 20:43:46.391945 [DEBUG] sofia.c:9086 IP 103.239.77.180 Rejected by acl "default". Falling back to Digest auth.
  7. 2018-07-04 20:43:46.391945 [WARNING] sofia_reg.c:1742 SIP auth challenge (INVITE) on sofia profile 'default' for [1300368909@103.226.53.10] from ip 103.239.77.180
  8. 2018-07-04 20:43:46.391945 [DEBUG] switch_core_state_machine.c:491 (sofia/default/7120041412@103.226.53.10) State NEW
  9. 2018-07-04 20:43:46.391945 [DEBUG] switch_core_session.c:1061 Send signal sofia/default/7120041412@103.226.53.10 [BREAK]
  10. 2018-07-04 20:43:46.391945 [DEBUG] sofia.c:2065 detaching session 20dd777c-7f77-11e8-894d-555946780031
  11. 2018-07-04 20:43:46.411947 [DEBUG] sofia.c:2173 Re-attaching to session 20dd777c-7f77-11e8-894d-555946780031
  12. 2018-07-04 20:43:46.411947 [DEBUG] switch_core_session.c:1061 Send signal sofia/default/7120041412@103.226.53.10 [BREAK]
  13. 2018-07-04 20:43:46.411947 [DEBUG] switch_core_session.c:1061 Send signal sofia/default/7120041412@103.226.53.10 [BREAK]
  14. 2018-07-04 20:43:46.432029 [DEBUG] sofia.c:8919 sofia/default/7120041412@103.226.53.10 receiving invite from 103.239.77.180:1126 version: 1.4.21  64bit
  15. 2018-07-04 20:43:46.432029 [DEBUG] sofia.c:9086 IP 103.239.77.180 Rejected by acl "default". Falling back to Digest auth.
  16. 2018-07-04 20:43:46.551938 [DEBUG] sofia.c:10184 Setting NAT mode based on via received
  17. 2018-07-04 20:43:46.551938 [DEBUG] sofia.c:6634 Channel sofia/default/7120041412@103.226.53.10 entering state [received][100]
  18. 2018-07-04 20:43:46.551938 [DEBUG] sofia.c:6644 Remote SDP:
  19. v=0
  20. o=7120041412 8000 8000 IN IP4 192.168.10.192
  21. s=SIP Call
  22. c=IN IP4 192.168.10.192
  23. t=0 0
  24. m=audio 5004 RTP/AVP 0 8 4 18 2 97 101
  25. a=rtpmap:0 PCMU/8000
  26. a=rtpmap:8 PCMA/8000
  27. a=rtpmap:4 G723/8000
  28. a=rtpmap:18 G729/8000
  29. a=fmtp:18 annexb=no
  30. a=rtpmap:2 G726-32/8000
  31. a=rtpmap:97 iLBC/8000
  32. a=fmtp:97 mode=20
  33. a=rtpmap:101 telephone-event/8000
  34. a=fmtp:101 0-16,32-36,54
  35. a=ptime:20
  36.  
  37. 2018-07-04 20:43:46.551938 [DEBUG] sofia.c:6910 (sofia/default/7120041412@103.226.53.10) State Change CS_NEW -> CS_INIT
  38. 2018-07-04 20:43:46.551938 [DEBUG] switch_core_session.c:1396 Send signal sofia/default/7120041412@103.226.53.10 [BREAK]
  39. 2018-07-04 20:43:46.551938 [DEBUG] switch_core_state_machine.c:472 (sofia/default/7120041412@103.226.53.10) Running State Change CS_INIT
  40. 2018-07-04 20:43:46.551938 [DEBUG] switch_core_state_machine.c:512 (sofia/default/7120041412@103.226.53.10) State INIT
  41. 2018-07-04 20:43:46.551938 [DEBUG] mod_sofia.c:87 sofia/default/7120041412@103.226.53.10 SOFIA INIT
  42. 2018-07-04 20:43:46.551938 [DEBUG] switch_core_state_machine.c:40 sofia/default/7120041412@103.226.53.10 Standard INIT
  43. 2018-07-04 20:43:46.551938 [DEBUG] switch_core_state_machine.c:48 (sofia/default/7120041412@103.226.53.10) State Change CS_INIT -> CS_ROUTING
  44. 2018-07-04 20:43:46.551938 [DEBUG] switch_core_session.c:1396 Send signal sofia/default/7120041412@103.226.53.10 [BREAK]
  45. 2018-07-04 20:43:46.551938 [DEBUG] switch_core_state_machine.c:512 (sofia/default/7120041412@103.226.53.10) State INIT going to sleep
  46. 2018-07-04 20:43:46.551938 [DEBUG] switch_core_state_machine.c:472 (sofia/default/7120041412@103.226.53.10) Running State Change CS_ROUTING
  47. 2018-07-04 20:43:46.551938 [DEBUG] switch_channel.c:2204 (sofia/default/7120041412@103.226.53.10) Callstate Change DOWN -> RINGING
  48. 2018-07-04 20:43:46.551938 [DEBUG] switch_core_state_machine.c:528 (sofia/default/7120041412@103.226.53.10) State ROUTING
  49. 2018-07-04 20:43:46.551938 [DEBUG] mod_sofia.c:123 sofia/default/7120041412@103.226.53.10 SOFIA ROUTING
  50. 2018-07-04 20:43:46.551938 [DEBUG] switch_core_state_machine.c:166 sofia/default/7120041412@103.226.53.10 Standard ROUTING
  51. 2018-07-04 20:43:46.551938 [INFO] mod_dialplan_xml.c:635 Processing 7120041412 <7120041412>->1300368909 in context default
  52. Dialplan: sofia/default/7120041412@103.226.53.10 parsing [default->] continue=false
  53. Dialplan: sofia/default/7120041412@103.226.53.10 Regex (PASS) [] destination_number(1300368909) =~ // break=on-false
  54. Dialplan: sofia/default/7120041412@103.226.53.10 Action set(callstart=2018-07-04 10:43:46)
  55. Dialplan: sofia/default/7120041412@103.226.53.10 Action set(call_processed=internal)
  56. Dialplan: sofia/default/7120041412@103.226.53.10 Action set(originated_destination_number=1300368909)
  57. Dialplan: sofia/default/7120041412@103.226.53.10 Action set(hangup_after_bridge=true)
  58. Dialplan: sofia/default/7120041412@103.226.53.10 Action set(continue_on_fail=true)
  59. Dialplan: sofia/default/7120041412@103.226.53.10 Action set(fax_enable_t38_request=true)
  60. Dialplan: sofia/default/7120041412@103.226.53.10 Action export(t38_passthru=true)
  61. Dialplan: sofia/default/7120041412@103.226.53.10 Action set(accountid=28)
  62. Dialplan: sofia/default/7120041412@103.226.53.10 Action set(account_type=0)
  63. Dialplan: sofia/default/7120041412@103.226.53.10 Action set(resellerid=0)
  64. Dialplan: sofia/default/7120041412@103.226.53.10 Action set(accountcode=98055562)
  65. Dialplan: sofia/default/7120041412@103.226.53.10 Action set(call_direction=outbound)
  66. Dialplan: sofia/default/7120041412@103.226.53.10 Action set(calltype=STANDARD)
  67. Dialplan: sofia/default/7120041412@103.226.53.10 Action sched_hangup(+6000 allotted_timeout)
  68. Dialplan: sofia/default/7120041412@103.226.53.10 Action log(INFO [Customer info] : [Account code: 98055562, Rategroup Id: 1, Called number: 1300368909])
  69. Dialplan: sofia/default/7120041412@103.226.53.10 Action set(origination_rates=ID:7|CODE:^13.*|DESTINATION:Australia|CONNECTIONCOST:0.35000|INCLUDEDSECONDS:0|COST:0.00000|INC:0|RATEGROUP:1|MARKUP:0|ACCID:28)
  70. Dialplan: sofia/default/7120041412@103.226.53.10 Action limit(db 98055562 db_98055562 11)
  71. Dialplan: sofia/default/7120041412@103.226.53.10 Action set(effective_destination_number=1300368909)
  72. Dialplan: sofia/default/7120041412@103.226.53.10 Action set(termination_rates=ID:7|CODE:^13.*|DESTINATION:Australia|CONNECTIONCOST:0.35000|INCLUDEDSECONDS:0|COST:0.00000|INC:0|TRUNK:2|PROVIDER:2)
  73. Dialplan: sofia/default/7120041412@103.226.53.10 Action export(rtp_append_audio_sdp=a=fmtp:18 annexb=no)
  74. Dialplan: sofia/default/7120041412@103.226.53.10 Action bridge(sofia/gateway/ivox/1300368909)
  75. Dialplan: sofia/default/7120041412@103.226.53.10 Action set(effective_destination_number=1300368909)
  76. Dialplan: sofia/default/7120041412@103.226.53.10 Action set(termination_rates=ID:4698|CODE:^13.*|DESTINATION:13 numbers|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:0.00000|INC:0|TRUNK:2|PROVIDER:2)
  77. Dialplan: sofia/default/7120041412@103.226.53.10 Action export(rtp_append_audio_sdp=a=fmtp:18 annexb=no)
  78. Dialplan: sofia/default/7120041412@103.226.53.10 Action bridge(sofia/gateway/ivox/1300368909)
  79. 2018-07-04 20:43:46.672000 [DEBUG] switch_core_state_machine.c:216 (sofia/default/7120041412@103.226.53.10) State Change CS_ROUTING -> CS_EXECUTE
  80. 2018-07-04 20:43:46.672000 [DEBUG] switch_core_session.c:1396 Send signal sofia/default/7120041412@103.226.53.10 [BREAK]
  81. 2018-07-04 20:43:46.672000 [DEBUG] switch_core_state_machine.c:528 (sofia/default/7120041412@103.226.53.10) State ROUTING going to sleep
  82. 2018-07-04 20:43:46.672000 [DEBUG] switch_core_state_machine.c:472 (sofia/default/7120041412@103.226.53.10) Running State Change CS_EXECUTE
  83. 2018-07-04 20:43:46.672000 [DEBUG] switch_core_state_machine.c:535 (sofia/default/7120041412@103.226.53.10) State EXECUTE
  84. 2018-07-04 20:43:46.672000 [DEBUG] mod_sofia.c:178 sofia/default/7120041412@103.226.53.10 SOFIA EXECUTE
  85. 2018-07-04 20:43:46.672000 [DEBUG] switch_core_state_machine.c:258 sofia/default/7120041412@103.226.53.10 Standard EXECUTE
  86. EXECUTE sofia/default/7120041412@103.226.53.10 set(callstart=2018-07-04 10:43:46)
  87. 2018-07-04 20:43:46.672000 [DEBUG] mod_dptools.c:1477 sofia/default/7120041412@103.226.53.10 SET [callstart]=[2018-07-04 10:43:46]
  88. EXECUTE sofia/default/7120041412@103.226.53.10 set(call_processed=internal)
  89. 2018-07-04 20:43:46.672000 [DEBUG] mod_dptools.c:1477 sofia/default/7120041412@103.226.53.10 SET [call_processed]=[internal]
  90. EXECUTE sofia/default/7120041412@103.226.53.10 set(originated_destination_number=1300368909)
  91. 2018-07-04 20:43:46.672000 [DEBUG] mod_dptools.c:1477 sofia/default/7120041412@103.226.53.10 SET [originated_destination_number]=[1300368909]
  92. EXECUTE sofia/default/7120041412@103.226.53.10 set(hangup_after_bridge=true)
  93. 2018-07-04 20:43:46.672000 [DEBUG] mod_dptools.c:1477 sofia/default/7120041412@103.226.53.10 SET [hangup_after_bridge]=[true]
  94. EXECUTE sofia/default/7120041412@103.226.53.10 set(continue_on_fail=true)
  95. 2018-07-04 20:43:46.672000 [DEBUG] mod_dptools.c:1477 sofia/default/7120041412@103.226.53.10 SET [continue_on_fail]=[true]
  96. EXECUTE sofia/default/7120041412@103.226.53.10 set(fax_enable_t38_request=true)
  97. 2018-07-04 20:43:46.672000 [DEBUG] mod_dptools.c:1477 sofia/default/7120041412@103.226.53.10 SET [fax_enable_t38_request]=[true]
  98. EXECUTE sofia/default/7120041412@103.226.53.10 export(t38_passthru=true)
  99. 2018-07-04 20:43:46.672000 [DEBUG] switch_channel.c:1267 EXPORT (export_vars) [t38_passthru]=[true]
  100. EXECUTE sofia/default/7120041412@103.226.53.10 set(accountid=28)
  101. 2018-07-04 20:43:46.672000 [DEBUG] mod_dptools.c:1477 sofia/default/7120041412@103.226.53.10 SET [accountid]=[28]
  102. EXECUTE sofia/default/7120041412@103.226.53.10 set(account_type=0)
  103. 2018-07-04 20:43:46.672000 [DEBUG] mod_dptools.c:1477 sofia/default/7120041412@103.226.53.10 SET [account_type]=[0]
  104. EXECUTE sofia/default/7120041412@103.226.53.10 set(resellerid=0)
  105. 2018-07-04 20:43:46.672000 [DEBUG] mod_dptools.c:1477 sofia/default/7120041412@103.226.53.10 SET [resellerid]=[0]
  106. EXECUTE sofia/default/7120041412@103.226.53.10 set(accountcode=98055562)
  107. 2018-07-04 20:43:46.672000 [DEBUG] mod_dptools.c:1477 sofia/default/7120041412@103.226.53.10 SET [accountcode]=[98055562]
  108. EXECUTE sofia/default/7120041412@103.226.53.10 set(call_direction=outbound)
  109. 2018-07-04 20:43:46.672000 [DEBUG] mod_dptools.c:1477 sofia/default/7120041412@103.226.53.10 SET [call_direction]=[outbound]
  110. EXECUTE sofia/default/7120041412@103.226.53.10 set(calltype=STANDARD)
  111. 2018-07-04 20:43:46.672000 [DEBUG] mod_dptools.c:1477 sofia/default/7120041412@103.226.53.10 SET [calltype]=[STANDARD]
  112. EXECUTE sofia/default/7120041412@103.226.53.10 sched_hangup(+6000 allotted_timeout)
  113. 2018-07-04 20:43:46.672000 [DEBUG] switch_scheduler.c:249 Added task 7 switch_ivr_schedule_hangup (20dd777c-7f77-11e8-894d-555946780031) to run at 1530707026
  114. EXECUTE sofia/default/7120041412@103.226.53.10 log(INFO [Customer info] : [Account code: 98055562, Rategroup Id: 1, Called number: 1300368909])
  115. 2018-07-04 20:43:46.672000 [INFO] mod_dptools.c:1670 [Customer info] : [Account code: 98055562, Rategroup Id: 1, Called number: 1300368909]
  116. EXECUTE sofia/default/7120041412@103.226.53.10 set(origination_rates=ID:7|CODE:^13.*|DESTINATION:Australia|CONNECTIONCOST:0.35000|INCLUDEDSECONDS:0|COST:0.00000|INC:0|RATEGROUP:1|MARKUP:0|ACCID:28)
  117. 2018-07-04 20:43:46.672000 [DEBUG] mod_dptools.c:1477 sofia/default/7120041412@103.226.53.10 SET [origination_rates]=[ID:7|CODE:^13.*|DESTINATION:Australia|CONNECTIONCOST:0.35000|INCLUDEDSECONDS:0|COST:0.00000|INC:0|RATEGROUP:1|MARKUP:0|ACCID:28]
  118. EXECUTE sofia/default/7120041412@103.226.53.10 limit(db 98055562 db_98055562 11)
  119. 2018-07-04 20:43:46.672000 [DEBUG] switch_limit.c:126 incr called: 98055562_db_98055562 max:11, interval:0
  120. 2018-07-04 20:43:46.672000 [DEBUG] mod_db.c:194 Usage for 98055562_db_98055562 is now 1/11
  121. EXECUTE sofia/default/7120041412@103.226.53.10 set(effective_destination_number=1300368909)
  122. 2018-07-04 20:43:46.672000 [DEBUG] mod_dptools.c:1477 sofia/default/7120041412@103.226.53.10 SET [effective_destination_number]=[1300368909]
  123. EXECUTE sofia/default/7120041412@103.226.53.10 set(termination_rates=ID:7|CODE:^13.*|DESTINATION:Australia|CONNECTIONCOST:0.35000|INCLUDEDSECONDS:0|COST:0.00000|INC:0|TRUNK:2|PROVIDER:2)
  124. 2018-07-04 20:43:46.672000 [DEBUG] mod_dptools.c:1477 sofia/default/7120041412@103.226.53.10 SET [termination_rates]=[ID:7|CODE:^13.*|DESTINATION:Australia|CONNECTIONCOST:0.35000|INCLUDEDSECONDS:0|COST:0.00000|INC:0|TRUNK:2|PROVIDER:2]
  125. EXECUTE sofia/default/7120041412@103.226.53.10 export(rtp_append_audio_sdp=a=fmtp:18 annexb=no)
  126. 2018-07-04 20:43:46.672000 [DEBUG] switch_channel.c:1267 EXPORT (export_vars) [rtp_append_audio_sdp]=[a=fmtp:18 annexb=no]
  127. EXECUTE sofia/default/7120041412@103.226.53.10 bridge(sofia/gateway/ivox/1300368909)
  128. 2018-07-04 20:43:46.672000 [DEBUG] switch_channel.c:1221 sofia/default/7120041412@103.226.53.10 EXPORTING[export_vars] [t38_passthru]=[true] to event
  129. 2018-07-04 20:43:46.672000 [DEBUG] switch_channel.c:1221 sofia/default/7120041412@103.226.53.10 EXPORTING[export_vars] [rtp_append_audio_sdp]=[a=fmtp:18 annexb=no] to event
  130. 2018-07-04 20:43:46.672000 [DEBUG] switch_ivr_originate.c:2101 Parsing global variables
  131. 2018-07-04 20:43:46.672000 [NOTICE] switch_channel.c:1075 New Channel sofia/default/1300368909 [210bd1a8-7f77-11e8-896a-555946780031]
  132. 2018-07-04 20:43:46.672000 [DEBUG] mod_sofia.c:4701 (sofia/default/1300368909) State Change CS_NEW -> CS_INIT
  133. 2018-07-04 20:43:46.672000 [DEBUG] switch_core_session.c:1396 Send signal sofia/default/1300368909 [BREAK]
  134. 2018-07-04 20:43:46.672000 [DEBUG] switch_core_state_machine.c:472 (sofia/default/1300368909) Running State Change CS_INIT
  135. 2018-07-04 20:43:46.672000 [DEBUG] switch_core_state_machine.c:512 (sofia/default/1300368909) State INIT
  136. 2018-07-04 20:43:46.672000 [DEBUG] mod_sofia.c:87 sofia/default/1300368909 SOFIA INIT
  137. 2018-07-04 20:43:46.672000 [DEBUG] sofia_glue.c:1241 sofia/default/1300368909 sending invite version: 1.4.21  64bit
  138. Local SDP:
  139. v=0
  140. o=FreeSWITCH 1530672266 1530672267 IN IP4 103.226.53.10
  141. s=FreeSWITCH
  142. c=IN IP4 103.226.53.10
  143. t=0 0
  144. m=audio 28760 RTP/AVP 0 8 18 9 101 13
  145. a=rtpmap:0 PCMU/8000
  146. a=rtpmap:8 PCMA/8000
  147. a=rtpmap:18 G729/8000
  148. a=rtpmap:9 G722/8000
  149. a=rtpmap:101 telephone-event/8000
  150. a=fmtp:101 0-16
  151. a=fmtp:18 annexb=no
  152. a=ptime:20
  153. a=sendrecv
  154.  
  155. 2018-07-04 20:43:46.672000 [DEBUG] switch_core_state_machine.c:40 sofia/default/1300368909 Standard INIT
  156. 2018-07-04 20:43:46.672000 [DEBUG] switch_core_state_machine.c:48 (sofia/default/1300368909) State Change CS_INIT -> CS_ROUTING
  157. 2018-07-04 20:43:46.672000 [DEBUG] switch_core_session.c:1396 Send signal sofia/default/1300368909 [BREAK]
  158. 2018-07-04 20:43:46.672000 [DEBUG] switch_core_state_machine.c:512 (sofia/default/1300368909) State INIT going to sleep
  159. 2018-07-04 20:43:46.672000 [DEBUG] switch_core_state_machine.c:472 (sofia/default/1300368909) Running State Change CS_ROUTING
  160. 2018-07-04 20:43:46.672000 [DEBUG] switch_core_session.c:1061 Send signal sofia/default/1300368909 [BREAK]
  161. 2018-07-04 20:43:46.672000 [DEBUG] sofia.c:6634 Channel sofia/default/1300368909 entering state [calling][0]
  162. 2018-07-04 20:43:46.672000 [DEBUG] switch_core_state_machine.c:528 (sofia/default/1300368909) State ROUTING
  163. 2018-07-04 20:43:46.672000 [DEBUG] mod_sofia.c:123 sofia/default/1300368909 SOFIA ROUTING
  164. 2018-07-04 20:43:46.672000 [DEBUG] switch_ivr_originate.c:67 (sofia/default/1300368909) State Change CS_ROUTING -> CS_CONSUME_MEDIA
  165. 2018-07-04 20:43:46.672000 [DEBUG] switch_core_session.c:1396 Send signal sofia/default/1300368909 [BREAK]
  166. 2018-07-04 20:43:46.672000 [DEBUG] switch_core_state_machine.c:528 (sofia/default/1300368909) State ROUTING going to sleep
  167. 2018-07-04 20:43:46.672000 [DEBUG] switch_core_state_machine.c:472 (sofia/default/1300368909) Running State Change CS_CONSUME_MEDIA
  168. 2018-07-04 20:43:46.672000 [DEBUG] switch_core_state_machine.c:547 (sofia/default/1300368909) State CONSUME_MEDIA
  169. 2018-07-04 20:43:46.672000 [DEBUG] switch_core_state_machine.c:547 (sofia/default/1300368909) State CONSUME_MEDIA going to sleep
  170. 2018-07-04 20:43:49.432027 [DEBUG] switch_core_session.c:1061 Send signal sofia/default/1300368909 [BREAK]
  171. 2018-07-04 20:43:49.432027 [DEBUG] switch_core_session.c:1061 Send signal sofia/default/1300368909 [BREAK]
  172. 2018-07-04 20:43:49.432027 [DEBUG] sofia.c:6634 Channel sofia/default/1300368909 entering state [proceeding][183]
  173. 2018-07-04 20:43:49.432027 [DEBUG] sofia.c:6644 Remote SDP:
  174. v=0
  175. o=- 1160355361 1160355361 IN IP4 202.83.183.33
  176. s=ENSResip
  177. c=IN IP4 27.34.224.16
  178. t=0 0
  179. m=audio 14194 RTP/AVP 0 101
  180. a=rtpmap:0 PCMU/8000
  181. a=rtpmap:101 telephone-event/8000
  182. a=fmtp:101 0-15
  183. a=ptime:20
  184. a=silenceSupp:off - - - -
  185.  
  186. 2018-07-04 20:43:49.432027 [DEBUG] switch_core_media.c:3680 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  187. 2018-07-04 20:43:49.432027 [DEBUG] switch_core_media.c:3735 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
  188. 2018-07-04 20:43:49.432027 [DEBUG] switch_core_media.c:3680 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  189. 2018-07-04 20:43:49.432027 [DEBUG] switch_core_media.c:3680 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G729:18:8000:20:8000:1]
  190. 2018-07-04 20:43:49.432027 [DEBUG] switch_core_media.c:3680 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  191. 2018-07-04 20:43:49.432027 [DEBUG] switch_core_media.c:3596 Set telephone-event payload to 101
  192. 2018-07-04 20:43:49.432027 [DEBUG] switch_core_media.c:2507 Set Codec sofia/default/1300368909 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
  193. 2018-07-04 20:43:49.432027 [DEBUG] switch_core_codec.c:111 sofia/default/1300368909 Original read codec set to PCMU:0
  194. 2018-07-04 20:43:49.432027 [DEBUG] switch_core_media.c:3934 Set 2833 dtmf send payload to 101
  195. 2018-07-04 20:43:49.432027 [DEBUG] switch_core_media.c:5179 AUDIO RTP [sofia/default/1300368909] 103.226.53.10 port 28760 -> 27.34.224.16 port 14194 codec: 0 ms: 20
  196. 2018-07-04 20:43:49.432027 [DEBUG] switch_rtp.c:3579 Starting timer [soft] 160 bytes per 20ms
  197. 2018-07-04 20:43:49.432027 [DEBUG] switch_core_media.c:5477 Set 2833 dtmf send payload to 101
  198. 2018-07-04 20:43:49.432027 [DEBUG] switch_core_media.c:5483 Set 2833 dtmf receive payload to 101
  199. 2018-07-04 20:43:49.432027 [DEBUG] switch_core_media.c:5505 sofia/default/1300368909 Set rtp dtmf delay to 40
  200. 2018-07-04 20:43:49.432027 [NOTICE] sofia_media.c:92 Pre-Answer sofia/default/1300368909!
  201. 2018-07-04 20:43:49.432027 [DEBUG] switch_channel.c:3415 Send signal sofia/default/7120041412@103.226.53.10 [BREAK]
  202. 2018-07-04 20:43:49.432027 [DEBUG] switch_channel.c:3419 (sofia/default/1300368909) Callstate Change DOWN -> EARLY
  203. 2018-07-04 20:43:49.432027 [INFO] switch_ivr_originate.c:3530 Sending early media
  204. 2018-07-04 20:43:49.432027 [DEBUG] switch_core_media.c:3680 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  205. 2018-07-04 20:43:49.432027 [DEBUG] switch_core_media.c:3680 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  206. 2018-07-04 20:43:49.432027 [DEBUG] switch_core_media.c:3735 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
  207. 2018-07-04 20:43:49.432027 [DEBUG] switch_core_media.c:3680 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G729:18:8000:20:8000:1]
  208. 2018-07-04 20:43:49.432027 [DEBUG] switch_core_media.c:3680 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  209. 2018-07-04 20:43:49.432027 [DEBUG] switch_core_media.c:3680 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  210. 2018-07-04 20:43:49.432027 [DEBUG] switch_core_media.c:3735 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
  211. 2018-07-04 20:43:49.432027 [DEBUG] switch_core_media.c:3680 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  212. 2018-07-04 20:43:49.432027 [DEBUG] switch_core_media.c:3680 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G729:18:8000:20:8000:1]
  213. 2018-07-04 20:43:49.432027 [DEBUG] switch_core_media.c:3680 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  214. 2018-07-04 20:43:49.432027 [DEBUG] switch_core_media.c:3680 Audio Codec Compare [G723:4:8000:20:6300:1]/[PCMA:8:8000:20:64000:1]
  215. 2018-07-04 20:43:49.432027 [DEBUG] switch_core_media.c:3680 Audio Codec Compare [G723:4:8000:20:6300:1]/[PCMU:0:8000:20:64000:1]
  216. 2018-07-04 20:43:49.432027 [DEBUG] switch_core_media.c:3680 Audio Codec Compare [G723:4:8000:20:6300:1]/[G729:18:8000:20:8000:1]
  217. 2018-07-04 20:43:49.432027 [DEBUG] switch_core_media.c:3680 Audio Codec Compare [G723:4:8000:20:6300:1]/[G722:9:8000:20:64000:1]
  218. 2018-07-04 20:43:49.432027 [DEBUG] switch_core_media.c:3680 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
  219. 2018-07-04 20:43:49.432027 [DEBUG] switch_core_media.c:3680 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
  220. 2018-07-04 20:43:49.432027 [DEBUG] switch_core_media.c:3680 Audio Codec Compare [G729:18:8000:20:8000:1]/[G729:18:8000:20:8000:1]
  221. 2018-07-04 20:43:49.432027 [DEBUG] switch_core_media.c:3735 Audio Codec Compare [G729:18:8000:20:8000:1] ++++ is saved as a match
  222. 2018-07-04 20:43:49.432027 [DEBUG] switch_core_media.c:3680 Audio Codec Compare [G729:18:8000:20:8000:1]/[G722:9:8000:20:64000:1]
  223. 2018-07-04 20:43:49.432027 [DEBUG] switch_core_media.c:3680 Audio Codec Compare [G726-32:2:8000:20:0:1]/[PCMA:8:8000:20:64000:1]
  224. 2018-07-04 20:43:49.432027 [DEBUG] switch_core_media.c:3680 Audio Codec Compare [G726-32:2:8000:20:0:1]/[PCMU:0:8000:20:64000:1]
  225. 2018-07-04 20:43:49.432027 [DEBUG] switch_core_media.c:3680 Audio Codec Compare [G726-32:2:8000:20:0:1]/[G729:18:8000:20:8000:1]
  226. 2018-07-04 20:43:49.432027 [DEBUG] switch_core_media.c:3680 Audio Codec Compare [G726-32:2:8000:20:0:1]/[G722:9:8000:20:64000:1]
  227. 2018-07-04 20:43:49.432027 [DEBUG] switch_core_media.c:3680 Audio Codec Compare [iLBC:97:8000:20:0:1]/[PCMA:8:8000:20:64000:1]
  228. 2018-07-04 20:43:49.432027 [DEBUG] switch_core_media.c:3680 Audio Codec Compare [iLBC:97:8000:20:0:1]/[PCMU:0:8000:20:64000:1]
  229. 2018-07-04 20:43:49.432027 [DEBUG] switch_core_media.c:3680 Audio Codec Compare [iLBC:97:8000:20:0:1]/[G729:18:8000:20:8000:1]
  230. 2018-07-04 20:43:49.432027 [DEBUG] switch_core_media.c:3680 Audio Codec Compare [iLBC:97:8000:20:0:1]/[G722:9:8000:20:64000:1]
  231. 2018-07-04 20:43:49.432027 [DEBUG] switch_core_media.c:3596 Set telephone-event payload to 101
  232. 2018-07-04 20:43:49.432027 [DEBUG] switch_core_media.c:2507 Set Codec sofia/default/7120041412@103.226.53.10 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
  233. 2018-07-04 20:43:49.432027 [DEBUG] switch_core_codec.c:111 sofia/default/7120041412@103.226.53.10 Original read codec set to PCMU:0
  234. 2018-07-04 20:43:49.432027 [DEBUG] switch_core_media.c:3943 Set 2833 dtmf send/recv payload to 101
  235. 2018-07-04 20:43:49.432027 [DEBUG] switch_core_media.c:5179 AUDIO RTP [sofia/default/7120041412@103.226.53.10] 103.226.53.10 port 20662 -> 192.168.10.192 port 5004 codec: 0 ms: 20
  236. 2018-07-04 20:43:49.432027 [DEBUG] switch_rtp.c:3579 Starting timer [soft] 160 bytes per 20ms
  237. 2018-07-04 20:43:49.432027 [DEBUG] switch_core_media.c:5477 Set 2833 dtmf send payload to 101
  238. 2018-07-04 20:43:49.432027 [DEBUG] switch_core_media.c:5483 Set 2833 dtmf receive payload to 101
  239. 2018-07-04 20:43:49.432027 [DEBUG] switch_core_media.c:5505 sofia/default/7120041412@103.226.53.10 Set rtp dtmf delay to 40
  240. 2018-07-04 20:43:49.432027 [NOTICE] sofia_media.c:92 Pre-Answer sofia/default/7120041412@103.226.53.10!
  241. 2018-07-04 20:43:49.432027 [DEBUG] switch_channel.c:3419 (sofia/default/7120041412@103.226.53.10) Callstate Change RINGING -> EARLY
  242. 2018-07-04 20:43:49.432027 [DEBUG] mod_sofia.c:2268 Ring SDP:
  243. v=0
  244. o=FreeSWITCH 1530680367 1530680368 IN IP4 103.226.53.10
  245. s=FreeSWITCH
  246. c=IN IP4 103.226.53.10
  247. t=0 0
  248. m=audio 20662 RTP/AVP 0 101
  249. a=rtpmap:0 PCMU/8000
  250. a=rtpmap:101 telephone-event/8000
  251. a=fmtp:101 0-16
  252. a=fmtp:18 annexb=no
  253. a=ptime:20
  254. a=sendrecv
  255.  
  256. 2018-07-04 20:43:49.432027 [DEBUG] switch_core_session.c:912 Send signal sofia/default/7120041412@103.226.53.10 [BREAK]
  257. 2018-07-04 20:43:49.432027 [DEBUG] switch_ivr_originate.c:3581 Originate Resulted in Success: [sofia/default/1300368909]
  258. 2018-07-04 20:43:49.432027 [DEBUG] switch_core_session.c:1061 Send signal sofia/default/7120041412@103.226.53.10 [BREAK]
  259. 2018-07-04 20:43:49.432027 [DEBUG] sofia.c:6634 Channel sofia/default/7120041412@103.226.53.10 entering state [early][183]
  260. 2018-07-04 20:43:49.432027 [DEBUG] switch_core_session.c:912 Send signal sofia/default/1300368909 [BREAK]
  261. 2018-07-04 20:43:49.432027 [DEBUG] switch_core_session.c:912 Send signal sofia/default/7120041412@103.226.53.10 [BREAK]
  262. 2018-07-04 20:43:49.432027 [DEBUG] switch_ivr_bridge.c:1468 (sofia/default/1300368909) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
  263. 2018-07-04 20:43:49.432027 [DEBUG] switch_core_session.c:1396 Send signal sofia/default/1300368909 [BREAK]
  264. 2018-07-04 20:43:49.432027 [DEBUG] switch_core_state_machine.c:472 (sofia/default/1300368909) Running State Change CS_EXCHANGE_MEDIA
  265. 2018-07-04 20:43:49.432027 [DEBUG] switch_core_state_machine.c:538 (sofia/default/1300368909) State EXCHANGE_MEDIA
  266. 2018-07-04 20:43:49.432027 [DEBUG] mod_sofia.c:594 SOFIA EXCHANGE_MEDIA
  267. 2018-07-04 20:43:49.511938 [DEBUG] switch_rtp.c:5894 Correct ip/port confirmed.
  268. 2018-07-04 20:43:49.752015 [INFO] switch_rtp.c:5867 Auto Changing port from 192.168.10.192:5004 to 103.239.77.180:5004
  269. 2018-07-04 20:43:50.671945 [DEBUG] switch_core_session.c:1061 Send signal sofia/default/1300368909 [BREAK]
  270. 2018-07-04 20:43:50.671945 [DEBUG] switch_core_session.c:1061 Send signal sofia/default/1300368909 [BREAK]
  271. 2018-07-04 20:43:50.691944 [DEBUG] sofia.c:6634 Channel sofia/default/1300368909 entering state [completing][200]
  272. 2018-07-04 20:43:50.691944 [DEBUG] sofia.c:6641 Duplicate SDP
  273. v=0
  274. o=- 1160355361 1160355361 IN IP4 202.83.183.33
  275. s=ENSResip
  276. c=IN IP4 27.34.224.16
  277. t=0 0
  278. m=audio 14194 RTP/AVP 0 101
  279. a=rtpmap:0 PCMU/8000
  280. a=rtpmap:101 telephone-event/8000
  281. a=fmtp:101 0-15
  282. a=ptime:20
  283. a=silenceSupp:off - - - -
  284.  
  285. 2018-07-04 20:43:50.691944 [DEBUG] switch_core_session.c:1061 Send signal sofia/default/1300368909 [BREAK]
  286. 2018-07-04 20:43:50.691944 [DEBUG] switch_core_session.c:1061 Send signal sofia/default/1300368909 [BREAK]
  287. 2018-07-04 20:43:50.711944 [DEBUG] sofia.c:6634 Channel sofia/default/1300368909 entering state [ready][200]
  288. 2018-07-04 20:43:50.711944 [DEBUG] switch_channel.c:3657 Send signal sofia/default/7120041412@103.226.53.10 [BREAK]
  289. 2018-07-04 20:43:50.711944 [NOTICE] sofia.c:7436 Channel [sofia/default/1300368909] has been answered
  290. 2018-07-04 20:43:50.711944 [DEBUG] switch_channel.c:3711 (sofia/default/1300368909) Callstate Change EARLY -> ACTIVE
  291. 2018-07-04 20:43:50.731943 [DEBUG] mod_sofia.c:780 Local SDP sofia/default/7120041412@103.226.53.10:
  292. v=0
  293. o=FreeSWITCH 1530680367 1530680369 IN IP4 103.226.53.10
  294. s=FreeSWITCH
  295. c=IN IP4 103.226.53.10
  296. t=0 0
  297. m=audio 20662 RTP/AVP 0 101
  298. a=rtpmap:0 PCMU/8000
  299. a=rtpmap:101 telephone-event/8000
  300. a=fmtp:101 0-16
  301. a=fmtp:18 annexb=no
  302. a=ptime:20
  303. a=sendrecv
  304.  
  305. 2018-07-04 20:43:50.731943 [DEBUG] switch_core_session.c:912 Send signal sofia/default/7120041412@103.226.53.10 [BREAK]
  306. 2018-07-04 20:43:50.731943 [DEBUG] switch_core_session.c:1061 Send signal sofia/default/7120041412@103.226.53.10 [BREAK]
  307. 2018-07-04 20:43:50.731943 [NOTICE] switch_ivr_bridge.c:496 Channel [sofia/default/7120041412@103.226.53.10] has been answered
  308. 2018-07-04 20:43:50.731943 [DEBUG] switch_channel.c:3711 (sofia/default/7120041412@103.226.53.10) Callstate Change EARLY -> ACTIVE
  309. 2018-07-04 20:43:50.731943 [DEBUG] sofia.c:6634 Channel sofia/default/7120041412@103.226.53.10 entering state [completed][200]
  310. 2018-07-04 20:43:50.731943 [DEBUG] switch_rtp.c:5894 Correct ip/port confirmed.
  311. 2018-07-04 20:43:50.851942 [DEBUG] switch_core_session.c:1061 Send signal sofia/default/7120041412@103.226.53.10 [BREAK]
  312. 2018-07-04 20:43:50.851942 [DEBUG] switch_core_session.c:1061 Send signal sofia/default/7120041412@103.226.53.10 [BREAK]
  313. 2018-07-04 20:43:50.851942 [DEBUG] switch_core_session.c:1061 Send signal sofia/default/7120041412@103.226.53.10 [BREAK]
  314. 2018-07-04 20:43:50.851942 [DEBUG] sofia.c:6634 Channel sofia/default/7120041412@103.226.53.10 entering state [ready][200]
  315. 2018-07-04 20:43:50.851942 [DEBUG] switch_core_session.c:978 Send signal sofia/default/1300368909 [BREAK]
  316. 2018-07-04 20:43:50.851942 [DEBUG] switch_core_session.c:978 Send signal sofia/default/7120041412@103.226.53.10 [BREAK]
  317. 2018-07-04 20:43:50.951938 [DEBUG] switch_rtp.c:5894 Correct ip/port confirmed.
  318. 2018-07-04 20:43:57.411945 [DEBUG] switch_core_session.c:1061 Send signal sofia/default/1300368909 [BREAK]
  319. 2018-07-04 20:43:57.411945 [DEBUG] switch_core_session.c:1061 Send signal sofia/default/1300368909 [BREAK]
  320. 2018-07-04 20:43:57.411945 [DEBUG] sofia.c:6634 Channel sofia/default/1300368909 entering state [received][100]
  321. 2018-07-04 20:43:57.411945 [DEBUG] sofia.c:6644 Remote SDP:
  322. v=0
  323. o=- 1160355361 1160355362 IN IP4 202.83.183.33
  324. s=ENSResip
  325. c=IN IP4 27.34.224.16
  326. t=0 0
  327. m=image 14502 udptl t38
  328. a=T38FaxVersion:0
  329. a=T38MaxBitRate:9600
  330. a=T38FaxMaxBuffer:200
  331. a=T38FaxMaxDatagram:72
  332. a=T38FaxRateManagement:transferredTCF
  333. a=T38FaxUdpEC:t38UDPRedundancy
  334. a=T38FaxFillBitRemoval:0
  335. a=T38FaxTranscodingMMR:0
  336. a=T38FaxTranscodingJBIG:0
  337.  
  338. 2018-07-04 20:43:57.411945 [DEBUG] switch_core_media.c:3374 Audio params changed for sofia/default/1300368909 from 27.34.224.16:14194 to 27.34.224.16:14502
  339. 2018-07-04 20:43:57.411945 [DEBUG] switch_core_media.c:3401 Passing T38 req to other leg.
  340. v=0
  341. o=- 1160355361 1160355362 IN IP4 202.83.183.33
  342. s=ENSResip
  343. c=IN IP4 27.34.224.16
  344. t=0 0
  345. m=image 14502 udptl t38
  346. a=T38FaxVersion:0
  347. a=T38MaxBitRate:9600
  348. a=T38FaxMaxBuffer:200
  349. a=T38FaxMaxDatagram:72
  350. a=T38FaxRateManagement:transferredTCF
  351. a=T38FaxUdpEC:t38UDPRedundancy
  352. a=T38FaxFillBitRemoval:0
  353. a=T38FaxTranscodingMMR:0
  354. a=T38FaxTranscodingJBIG:0
  355.  
  356. 2018-07-04 20:43:57.411945 [DEBUG] switch_core_session.c:978 Send signal sofia/default/7120041412@103.226.53.10 [BREAK]
  357. 2018-07-04 20:43:57.432028 [DEBUG] switch_core_media.c:7413 sofia/default/7120041412@103.226.53.10 image media sdp:
  358. v=0
  359. o=FreeSWITCH 1530680367 1530680370 IN IP4 103.226.53.10
  360. s=FreeSWITCH
  361. c=IN IP4 103.226.53.10
  362. t=0 0
  363. m=image 20662 udptl t38
  364. a=T38FaxVersion:0
  365. a=T38MaxBitRate:9600
  366. a=T38FaxRateManagement:transferredTCF
  367. a=T38FaxMaxBuffer:200
  368. a=T38FaxMaxDatagram:72
  369. a=T38FaxUdpEC:t38UDPRedundancy
  370.  
  371. 2018-07-04 20:43:57.432028 [DEBUG] sofia_glue.c:1241 sofia/default/7120041412@103.226.53.10 sending invite version: 1.4.21  64bit
  372. Local SDP:
  373. v=0
  374. o=FreeSWITCH 1530680367 1530680370 IN IP4 103.226.53.10
  375. s=FreeSWITCH
  376. c=IN IP4 103.226.53.10
  377. t=0 0
  378. m=image 20662 udptl t38
  379. a=T38FaxVersion:0
  380. a=T38MaxBitRate:9600
  381. a=T38FaxRateManagement:transferredTCF
  382. a=T38FaxMaxBuffer:200
  383. a=T38FaxMaxDatagram:72
  384. a=T38FaxUdpEC:t38UDPRedundancy
  385.  
  386. 2018-07-04 20:43:57.432028 [DEBUG] switch_core_session.c:1061 Send signal sofia/default/7120041412@103.226.53.10 [BREAK]
  387. 2018-07-04 20:43:57.432028 [DEBUG] sofia.c:6634 Channel sofia/default/7120041412@103.226.53.10 entering state [calling][0]
  388. 2018-07-04 20:43:57.491941 [DEBUG] switch_core_session.c:1061 Send signal sofia/default/7120041412@103.226.53.10 [BREAK]
  389. 2018-07-04 20:43:57.491941 [DEBUG] switch_core_session.c:1061 Send signal sofia/default/7120041412@103.226.53.10 [BREAK]
  390. 2018-07-04 20:43:57.491941 [DEBUG] switch_core_media.c:4615 Remote address:port [192.168.10.192:5004] has not changed.
  391. 2018-07-04 20:43:57.491941 [DEBUG] sofia.c:6219 Passing 200 OK to other leg
  392. 2018-07-04 20:43:57.491941 [DEBUG] switch_core_media.c:524 Audio params are unchanged for sofia/default/7120041412@103.226.53.10.
  393. 2018-07-04 20:43:57.491941 [INFO] sofia.c:6268 Activating T38 Passthru
  394. 2018-07-04 20:43:57.491941 [DEBUG] switch_core_session.c:978 Send signal sofia/default/1300368909 [BREAK]
  395. 2018-07-04 20:43:57.491941 [DEBUG] sofia.c:6634 Channel sofia/default/7120041412@103.226.53.10 entering state [completing][200]
  396. 2018-07-04 20:43:57.491941 [DEBUG] sofia.c:6641 Duplicate SDP
  397. v=0
  398. o=7120041412 8000 8001 IN IP4 192.168.10.192
  399. s=SIP Call
  400. c=IN IP4 192.168.10.192
  401. t=0 0
  402. m=image 5004 udptl t38
  403. a=T38FaxVersion:0
  404. a=T38MaxBitRate:9600
  405. a=T38FaxRateManagement:transferredTCF
  406. a=T38FaxMaxBuffer:200
  407. a=T38FaxMaxDatagram:72
  408. a=T38FaxUdpEC:t38UDPRedundancy
  409.  
  410. 2018-07-04 20:43:57.491941 [DEBUG] switch_core_session.c:1061 Send signal sofia/default/7120041412@103.226.53.10 [BREAK]
  411. 2018-07-04 20:43:57.491941 [DEBUG] switch_core_session.c:1061 Send signal sofia/default/7120041412@103.226.53.10 [BREAK]
  412. 2018-07-04 20:43:57.491941 [DEBUG] mod_sofia.c:1983 Responding with 200 [OK]
  413. 2018-07-04 20:43:57.491941 [DEBUG] switch_core_media.c:7413 sofia/default/1300368909 image media sdp:
  414. v=0
  415. o=FreeSWITCH 1530672266 1530672268 IN IP4 103.226.53.10
  416. s=FreeSWITCH
  417. c=IN IP4 103.226.53.10
  418. t=0 0
  419. m=image 28760 udptl t38
  420. a=T38FaxVersion:0
  421. a=T38MaxBitRate:9600
  422. a=T38FaxFillBitRemoval:0
  423. a=T38FaxTranscodingMMR:0
  424. a=T38FaxTranscodingJBIG:0
  425. a=T38FaxRateManagement:transferredTCF
  426. a=T38FaxMaxBuffer:200
  427. a=T38FaxMaxDatagram:72
  428. a=T38FaxUdpEC:t38UDPRedundancy
  429.  
  430. 2018-07-04 20:43:57.491941 [DEBUG] switch_core_session.c:912 Send signal sofia/default/1300368909 [BREAK]
  431. 2018-07-04 20:43:57.491941 [DEBUG] switch_core_session.c:1061 Send signal sofia/default/1300368909 [BREAK]
  432. 2018-07-04 20:43:57.491941 [DEBUG] sofia.c:6634 Channel sofia/default/1300368909 entering state [completed][200]
  433. 2018-07-04 20:43:57.511949 [DEBUG] sofia.c:6634 Channel sofia/default/7120041412@103.226.53.10 entering state [ready][200]
  434. 2018-07-04 20:43:57.611939 [DEBUG] switch_core_session.c:1061 Send signal sofia/default/1300368909 [BREAK]
  435. 2018-07-04 20:43:57.611939 [DEBUG] switch_core_session.c:1061 Send signal sofia/default/1300368909 [BREAK]
  436. 2018-07-04 20:43:57.611939 [DEBUG] switch_core_session.c:1061 Send signal sofia/default/1300368909 [BREAK]
  437. 2018-07-04 20:43:57.611939 [DEBUG] sofia.c:6634 Channel sofia/default/1300368909 entering state [ready][200]
  438. 2018-07-04 20:44:29.551942 [DEBUG] switch_core_session.c:1061 Send signal sofia/default/7120041412@103.226.53.10 [BREAK]
  439. 2018-07-04 20:44:29.551942 [NOTICE] sofia.c:952 Hangup sofia/default/7120041412@103.226.53.10 [CS_EXECUTE] [NORMAL_CLEARING]
  440. 2018-07-04 20:44:29.551942 [DEBUG] switch_channel.c:3242 Send signal sofia/default/7120041412@103.226.53.10 [KILL]
  441. 2018-07-04 20:44:29.551942 [DEBUG] switch_core_session.c:1396 Send signal sofia/default/7120041412@103.226.53.10 [BREAK]
  442. 2018-07-04 20:44:29.551942 [DEBUG] switch_ivr_bridge.c:660 BRIDGE THREAD DONE [sofia/default/7120041412@103.226.53.10]
  443. 2018-07-04 20:44:29.551942 [DEBUG] switch_ivr_bridge.c:690 Send signal sofia/default/1300368909 [BREAK]
  444. 2018-07-04 20:44:29.551942 [DEBUG] switch_ivr_bridge.c:660 BRIDGE THREAD DONE [sofia/default/1300368909]
  445. 2018-07-04 20:44:29.551942 [DEBUG] switch_ivr_bridge.c:690 Send signal sofia/default/7120041412@103.226.53.10 [BREAK]
  446. 2018-07-04 20:44:29.551942 [NOTICE] switch_ivr_bridge.c:758 Hangup sofia/default/1300368909 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING]
  447. 2018-07-04 20:44:29.551942 [DEBUG] switch_channel.c:3242 Send signal sofia/default/1300368909 [KILL]
  448. 2018-07-04 20:44:29.551942 [DEBUG] switch_core_session.c:1396 Send signal sofia/default/1300368909 [BREAK]
  449. 2018-07-04 20:44:29.551942 [DEBUG] switch_core_state_machine.c:538 (sofia/default/1300368909) State EXCHANGE_MEDIA going to sleep
  450. 2018-07-04 20:44:29.551942 [DEBUG] switch_core_state_machine.c:472 (sofia/default/1300368909) Running State Change CS_HANGUP
  451. 2018-07-04 20:44:29.551942 [DEBUG] switch_core_state_machine.c:735 (sofia/default/1300368909) Callstate Change ACTIVE -> HANGUP
  452. 2018-07-04 20:44:29.551942 [DEBUG] switch_core_state_machine.c:737 (sofia/default/1300368909) State HANGUP
  453. 2018-07-04 20:44:29.551942 [DEBUG] mod_sofia.c:407 sofia/default/1300368909 Overriding SIP cause 480 with 200 from the other leg
  454. 2018-07-04 20:44:29.551942 [DEBUG] mod_sofia.c:413 Channel sofia/default/1300368909 hanging up, cause: NORMAL_CLEARING
  455. 2018-07-04 20:44:29.551942 [DEBUG] switch_ivr_bridge.c:1566 sofia/default/1300368909 skip receive message [UNBRIDGE] (channel is hungup already)
  456. 2018-07-04 20:44:29.551942 [DEBUG] switch_ivr_bridge.c:1569 sofia/default/7120041412@103.226.53.10 skip receive message [UNBRIDGE] (channel is hungup already)
  457. 2018-07-04 20:44:29.551942 [DEBUG] switch_core_session.c:2902 sofia/default/7120041412@103.226.53.10 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
  458. 2018-07-04 20:44:29.551942 [DEBUG] mod_sofia.c:465 Sending BYE to sofia/default/1300368909
  459. 2018-07-04 20:44:29.551942 [DEBUG] switch_core_state_machine.c:535 (sofia/default/7120041412@103.226.53.10) State EXECUTE going to sleep
  460. 2018-07-04 20:44:29.551942 [DEBUG] switch_core_state_machine.c:472 (sofia/default/7120041412@103.226.53.10) Running State Change CS_HANGUP
  461. 2018-07-04 20:44:29.551942 [DEBUG] switch_core_state_machine.c:735 (sofia/default/7120041412@103.226.53.10) Callstate Change ACTIVE -> HANGUP
  462. 2018-07-04 20:44:29.551942 [DEBUG] switch_core_state_machine.c:60 sofia/default/1300368909 Standard HANGUP, cause: NORMAL_CLEARING
  463. 2018-07-04 20:44:29.551942 [DEBUG] switch_core_state_machine.c:737 (sofia/default/1300368909) State HANGUP going to sleep
  464. 2018-07-04 20:44:29.551942 [DEBUG] switch_core_state_machine.c:504 (sofia/default/1300368909) State Change CS_HANGUP -> CS_REPORTING
  465. 2018-07-04 20:44:29.551942 [DEBUG] switch_core_session.c:1396 Send signal sofia/default/1300368909 [BREAK]
  466. 2018-07-04 20:44:29.551942 [DEBUG] switch_core_state_machine.c:472 (sofia/default/1300368909) Running State Change CS_REPORTING
  467. 2018-07-04 20:44:29.551942 [DEBUG] switch_core_state_machine.c:737 (sofia/default/7120041412@103.226.53.10) State HANGUP
  468. 2018-07-04 20:44:29.551942 [DEBUG] mod_sofia.c:413 Channel sofia/default/7120041412@103.226.53.10 hanging up, cause: NORMAL_CLEARING
  469. 2018-07-04 20:44:29.551942 [DEBUG] switch_core_state_machine.c:823 (sofia/default/1300368909) State REPORTING
  470. 2018-07-04 20:44:29.551942 [DEBUG] switch_core_state_machine.c:60 sofia/default/7120041412@103.226.53.10 Standard HANGUP, cause: NORMAL_CLEARING
  471. 2018-07-04 20:44:29.551942 [DEBUG] switch_core_state_machine.c:737 (sofia/default/7120041412@103.226.53.10) State HANGUP going to sleep
  472. 2018-07-04 20:44:29.551942 [DEBUG] switch_core_state_machine.c:504 (sofia/default/7120041412@103.226.53.10) State Change CS_HANGUP -> CS_REPORTING
  473. 2018-07-04 20:44:29.551942 [DEBUG] switch_core_session.c:1396 Send signal sofia/default/7120041412@103.226.53.10 [BREAK]
  474. 2018-07-04 20:44:29.551942 [DEBUG] switch_core_state_machine.c:472 (sofia/default/7120041412@103.226.53.10) Running State Change CS_REPORTING
  475. 2018-07-04 20:44:29.551942 [DEBUG] switch_core_state_machine.c:823 (sofia/default/7120041412@103.226.53.10) State REPORTING
  476. 2018-07-04 20:44:29.891946 [DEBUG] switch_core_state_machine.c:104 sofia/default/1300368909 Standard REPORTING, cause: NORMAL_CLEARING
  477. 2018-07-04 20:44:29.891946 [DEBUG] switch_core_state_machine.c:823 (sofia/default/1300368909) State REPORTING going to sleep
  478. 2018-07-04 20:44:29.891946 [DEBUG] switch_core_state_machine.c:498 (sofia/default/1300368909) State Change CS_REPORTING -> CS_DESTROY
  479. 2018-07-04 20:44:29.891946 [DEBUG] switch_core_session.c:1396 Send signal sofia/default/1300368909 [BREAK]
  480. 2018-07-04 20:44:29.891946 [DEBUG] switch_core_session.c:1623 Session 11 (sofia/default/1300368909) Locked, Waiting on external entities
  481. 2018-07-04 20:44:29.891946 [NOTICE] switch_core_session.c:1641 Session 11 (sofia/default/1300368909) Ended
  482. 2018-07-04 20:44:29.891946 [NOTICE] switch_core_session.c:1645 Close Channel sofia/default/1300368909 [CS_DESTROY]
  483. 2018-07-04 20:44:29.891946 [DEBUG] switch_core_state_machine.c:626 (sofia/default/1300368909) Running State Change CS_DESTROY
  484. 2018-07-04 20:44:29.891946 [DEBUG] switch_core_state_machine.c:636 (sofia/default/1300368909) State DESTROY
  485. 2018-07-04 20:44:29.891946 [DEBUG] mod_sofia.c:323 sofia/default/1300368909 SOFIA DESTROY
  486. 2018-07-04 20:44:29.891946 [DEBUG] switch_core_state_machine.c:111 sofia/default/1300368909 Standard DESTROY
  487. 2018-07-04 20:44:29.891946 [DEBUG] switch_core_state_machine.c:636 (sofia/default/1300368909) State DESTROY going to sleep
  488. 2018-07-04 20:44:30.111934 [DEBUG] switch_core_state_machine.c:104 sofia/default/7120041412@103.226.53.10 Standard REPORTING, cause: NORMAL_CLEARING
  489. 2018-07-04 20:44:30.111934 [DEBUG] switch_core_state_machine.c:823 (sofia/default/7120041412@103.226.53.10) State REPORTING going to sleep
  490. 2018-07-04 20:44:30.111934 [DEBUG] switch_core_state_machine.c:498 (sofia/default/7120041412@103.226.53.10) State Change CS_REPORTING -> CS_DESTROY
  491. 2018-07-04 20:44:30.111934 [DEBUG] switch_core_session.c:1396 Send signal sofia/default/7120041412@103.226.53.10 [BREAK]
  492. 2018-07-04 20:44:30.111934 [DEBUG] switch_core_session.c:1623 Session 10 (sofia/default/7120041412@103.226.53.10) Locked, Waiting on external entities
  493. 2018-07-04 20:44:30.111934 [NOTICE] switch_core_session.c:1641 Session 10 (sofia/default/7120041412@103.226.53.10) Ended
  494. 2018-07-04 20:44:30.111934 [NOTICE] switch_core_session.c:1645 Close Channel sofia/default/7120041412@103.226.53.10 [CS_DESTROY]
  495. 2018-07-04 20:44:30.111934 [DEBUG] switch_core_state_machine.c:626 (sofia/default/7120041412@103.226.53.10) Running State Change CS_DESTROY
  496. 2018-07-04 20:44:30.111934 [DEBUG] switch_core_state_machine.c:636 (sofia/default/7120041412@103.226.53.10) State DESTROY
  497. 2018-07-04 20:44:30.111934 [DEBUG] mod_sofia.c:323 sofia/default/7120041412@103.226.53.10 SOFIA DESTROY
  498. 2018-07-04 20:44:30.111934 [DEBUG] switch_core_state_machine.c:111 sofia/default/7120041412@103.226.53.10 Standard DESTROY
  499. 2018-07-04 20:44:30.111934 [DEBUG] switch_core_state_machine.c:636 (sofia/default/7120041412@103.226.53.10) State DESTROY going to sleep
  500. 2018-07-04 20:44:30.211936 [DEBUG] switch_scheduler.c:144 Deleting task 7 switch_ivr_schedule_hangup (20dd777c-7f77-11e8-894d-555946780031)
  501.  
  502.