From Test, 5 Months ago, written in HTML5.
- go back
Embed
Viewing differences between and FAX
  1. 2024-06-25 07:46:13.292038 [INFO] mod_dialplan_xml.c:637 Processing 27876303987 <27876303987>->27448734188 in context default
  2. Dialplan: sofia/default/27876303987@102.220.232.19 parsing [default->] continue=false
  3. Dialplan: sofia/default/27876303987@102.220.232.19 Regex (PASS) [] destination_number(27448734188) =~ // break=on-false
  4. Dialplan: sofia/default/27876303987@102.220.232.19 Action set(callstart=2024-06-25 05:46:13)
  5. Dialplan: sofia/default/27876303987@102.220.232.19 Action set(call_processed=internal)
  6. Dialplan: sofia/default/27876303987@102.220.232.19 Action set(originated_destination_number=27448734188)
  7. Dialplan: sofia/default/27876303987@102.220.232.19 Action set(hangup_after_bridge=true)
  8. Dialplan: sofia/default/27876303987@102.220.232.19 Action set(continue_on_fail=true)
  9. Dialplan: sofia/default/27876303987@102.220.232.19 Action set(fax_enable_t38=true)
  10. Dialplan: sofia/default/27876303987@102.220.232.19 Action set(fax_enable_t38_request=true)
  11. Dialplan: sofia/default/27876303987@102.220.232.19 Action export(t38_passthru=true)
  12. Dialplan: sofia/default/27876303987@102.220.232.19 Action set(accountid=2270)
  13. Dialplan: sofia/default/27876303987@102.220.232.19 Action set(account_type=0)
  14. Dialplan: sofia/default/27876303987@102.220.232.19 Action set(resellerid=0)
  15. Dialplan: sofia/default/27876303987@102.220.232.19 Action set(accountcode=7439137964)
  16. Dialplan: sofia/default/27876303987@102.220.232.19 Action set(call_direction=outbound)
  17. Dialplan: sofia/default/27876303987@102.220.232.19 Action set(calltype=STANDARD)
  18. Dialplan: sofia/default/27876303987@102.220.232.19 Action sched_hangup(+5400 allotted_timeout)
  19. Dialplan: sofia/default/27876303987@102.220.232.19 Action log(INFO [Customer info] : [Account code: 7439137964, Rategroup Id: 189, Called number: 27448734188])
  20. Dialplan: sofia/default/27876303987@102.220.232.19 Action set(origination_rates=ID:349049768|CODE:^2744873.*|DESTINATION:RSA Telkom Geographic|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:0.33000|INC:1|RATEGROUP:189|MARKUP:0|ACCID:2270)
  21. Dialplan: sofia/default/27876303987@102.220.232.19 Action limit(db 7439137964 db_7439137964 6/1)
  22. Dialplan: sofia/default/27876303987@102.220.232.19 Action set(effective_destination_number=27448734188)
  23. Dialplan: sofia/default/27876303987@102.220.232.19 Action set(termination_rates=ID:4278012|CODE:^2744873.*|DESTINATION:RSA Telkom Geographic|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:0.09000|INC:1|TRUNK:3|PROVIDER:37)
  24. Dialplan: sofia/default/27876303987@102.220.232.19 Action export(rtp_append_audio_sdp=a=fmtp:18 annexb=no)
  25. Dialplan: sofia/default/27876303987@102.220.232.19 Action set(absolute_codec_string=^^:G729:PCMA:PCMU)
  26. Dialplan: sofia/default/27876303987@102.220.232.19 Action limit_execute(db Transit_JHB_BRY_SBC gw_Transit_JHB_BRY_SBC 500 bridge {absolute_codec_string=^^:G729:PCMA:PCMU}sofia/gateway/Transit_JHB_BRY_SBC/27448734188)
  27. Dialplan: sofia/default/27876303987@102.220.232.19 Action bridge(sofia/gateway/Transit_JHB_PKL_SBC/27448734188)
  28. Dialplan: sofia/default/27876303987@102.220.232.19 Action bridge(sofia/gateway/Transit_CPT_BREE_SBC/27448734188)
  29. Dialplan: sofia/default/27876303987@102.220.232.19 Action set(effective_destination_number=27448734188)
  30. Dialplan: sofia/default/27876303987@102.220.232.19 Action set(termination_rates=ID:4296332|CODE:^274487.*|DESTINATION:RSA Telkom Geographic|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:0.09000|INC:1|TRUNK:3|PROVIDER:37)
  31. Dialplan: sofia/default/27876303987@102.220.232.19 Action export(rtp_append_audio_sdp=a=fmtp:18 annexb=no)
  32. Dialplan: sofia/default/27876303987@102.220.232.19 Action set(absolute_codec_string=^^:G729:PCMA:PCMU)
  33. Dialplan: sofia/default/27876303987@102.220.232.19 Action limit_execute(db Transit_JHB_BRY_SBC gw_Transit_JHB_BRY_SBC 500 bridge {absolute_codec_string=^^:G729:PCMA:PCMU}sofia/gateway/Transit_JHB_BRY_SBC/27448734188)
  34. Dialplan: sofia/default/27876303987@102.220.232.19 Action bridge(sofia/gateway/Transit_JHB_PKL_SBC/27448734188)
  35. Dialplan: sofia/default/27876303987@102.220.232.19 Action bridge(sofia/gateway/Transit_CPT_BREE_SBC/27448734188)
  36. 2024-06-25 07:46:13.472092 [DEBUG] switch_core_state_machine.c:286 (sofia/default/27876303987@102.220.232.19) State Change CS_ROUTING -> CS_EXECUTE
  37. 2024-06-25 07:46:13.472092 [DEBUG] switch_core_state_machine.c:602 (sofia/default/27876303987@102.220.232.19) State ROUTING going to sleep
  38. 2024-06-25 07:46:13.472092 [DEBUG] switch_core_state_machine.c:543 (sofia/default/27876303987@102.220.232.19) Running State Change CS_EXECUTE
  39. 2024-06-25 07:46:13.472092 [DEBUG] switch_core_state_machine.c:609 (sofia/default/27876303987@102.220.232.19) State EXECUTE
  40. 2024-06-25 07:46:13.472092 [DEBUG] mod_sofia.c:197 sofia/default/27876303987@102.220.232.19 SOFIA EXECUTE
  41. 2024-06-25 07:46:13.472092 [DEBUG] switch_core_state_machine.c:328 sofia/default/27876303987@102.220.232.19 Standard EXECUTE
  42. EXECUTE sofia/default/27876303987@102.220.232.19 set(callstart=2024-06-25 05:46:13)
  43. 2024-06-25 07:46:13.472092 [DEBUG] mod_dptools.c:1519 SET sofia/default/27876303987@102.220.232.19 [callstart]=[2024-06-25 05:46:13]
  44. EXECUTE sofia/default/27876303987@102.220.232.19 set(call_processed=internal)
  45. 2024-06-25 07:46:13.472092 [DEBUG] mod_dptools.c:1519 SET sofia/default/27876303987@102.220.232.19 [call_processed]=[internal]
  46. EXECUTE sofia/default/27876303987@102.220.232.19 set(originated_destination_number=27448734188)
  47. 2024-06-25 07:46:13.472092 [DEBUG] mod_dptools.c:1519 SET sofia/default/27876303987@102.220.232.19 [originated_destination_number]=[27448734188]
  48. EXECUTE sofia/default/27876303987@102.220.232.19 set(hangup_after_bridge=true)
  49. 2024-06-25 07:46:13.472092 [DEBUG] mod_dptools.c:1519 SET sofia/default/27876303987@102.220.232.19 [hangup_after_bridge]=[true]
  50. EXECUTE sofia/default/27876303987@102.220.232.19 set(continue_on_fail=true)
  51. 2024-06-25 07:46:13.472092 [DEBUG] mod_dptools.c:1519 SET sofia/default/27876303987@102.220.232.19 [continue_on_fail]=[true]
  52. EXECUTE sofia/default/27876303987@102.220.232.19 set(fax_enable_t38=true)
  53. 2024-06-25 07:46:13.472092 [DEBUG] mod_dptools.c:1519 SET sofia/default/27876303987@102.220.232.19 [fax_enable_t38]=[true]
  54. EXECUTE sofia/default/27876303987@102.220.232.19 set(fax_enable_t38_request=true)
  55. 2024-06-25 07:46:13.472092 [DEBUG] mod_dptools.c:1519 SET sofia/default/27876303987@102.220.232.19 [fax_enable_t38_request]=[true]
  56. EXECUTE sofia/default/27876303987@102.220.232.19 export(t38_passthru=true)
  57. 2024-06-25 07:46:13.472092 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [t38_passthru]=[true]
  58. EXECUTE sofia/default/27876303987@102.220.232.19 set(accountid=2270)
  59. 2024-06-25 07:46:13.472092 [DEBUG] mod_dptools.c:1519 SET sofia/default/27876303987@102.220.232.19 [accountid]=[2270]
  60. EXECUTE sofia/default/27876303987@102.220.232.19 set(account_type=0)
  61. 2024-06-25 07:46:13.472092 [DEBUG] mod_dptools.c:1519 SET sofia/default/27876303987@102.220.232.19 [account_type]=[0]
  62. EXECUTE sofia/default/27876303987@102.220.232.19 set(resellerid=0)
  63. 2024-06-25 07:46:13.472092 [DEBUG] mod_dptools.c:1519 SET sofia/default/27876303987@102.220.232.19 [resellerid]=[0]
  64. EXECUTE sofia/default/27876303987@102.220.232.19 set(accountcode=7439137964)
  65. 2024-06-25 07:46:13.472092 [DEBUG] mod_dptools.c:1519 SET sofia/default/27876303987@102.220.232.19 [accountcode]=[7439137964]
  66. EXECUTE sofia/default/27876303987@102.220.232.19 set(call_direction=outbound)
  67. 2024-06-25 07:46:13.472092 [DEBUG] mod_dptools.c:1519 SET sofia/default/27876303987@102.220.232.19 [call_direction]=[outbound]
  68. EXECUTE sofia/default/27876303987@102.220.232.19 set(calltype=STANDARD)
  69. 2024-06-25 07:46:13.472092 [DEBUG] mod_dptools.c:1519 SET sofia/default/27876303987@102.220.232.19 [calltype]=[STANDARD]
  70. EXECUTE sofia/default/27876303987@102.220.232.19 sched_hangup(+5400 allotted_timeout)
  71. 2024-06-25 07:46:13.472092 [DEBUG] switch_scheduler.c:249 Added task 2738361 switch_ivr_schedule_hangup (a5d94864-7170-4506-84a1-e088245af79a) to run at 1719299773
  72. EXECUTE sofia/default/27876303987@102.220.232.19 log(INFO [Customer info] : [Account code: 7439137964, Rategroup Id: 189, Called number: 27448734188])
  73. 2024-06-25 07:46:13.472092 [INFO] mod_dptools.c:1713 [Customer info] : [Account code: 7439137964, Rategroup Id: 189, Called number: 27448734188]
  74. EXECUTE sofia/default/27876303987@102.220.232.19 set(origination_rates=ID:349049768|CODE:^2744873.*|DESTINATION:RSA Telkom Geographic|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:0.33000|INC:1|RATEGROUP:189|MARKUP:0|ACCID:2270)
  75. 2024-06-25 07:46:13.472092 [DEBUG] mod_dptools.c:1519 SET sofia/default/27876303987@102.220.232.19 [origination_rates]=[ID:349049768|CODE:^2744873.*|DESTINATION:RSA Telkom Geographic|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:0.33000|INC:1|RATEGROUP:189|MARKUP:0|ACCID:2270]
  76. EXECUTE sofia/default/27876303987@102.220.232.19 limit(db 7439137964 db_7439137964 6/1)
  77. 2024-06-25 07:46:13.472092 [DEBUG] switch_limit.c:126 incr called: 7439137964_db_7439137964 max:6, interval:1
  78. 2024-06-25 07:46:13.472092 [DEBUG] mod_db.c:194 Usage for 7439137964_db_7439137964 is now 1/6
  79. EXECUTE sofia/default/27876303987@102.220.232.19 set(effective_destination_number=27448734188)
  80. 2024-06-25 07:46:13.472092 [DEBUG] mod_dptools.c:1519 SET sofia/default/27876303987@102.220.232.19 [effective_destination_number]=[27448734188]
  81. EXECUTE sofia/default/27876303987@102.220.232.19 set(termination_rates=ID:4278012|CODE:^2744873.*|DESTINATION:RSA Telkom Geographic|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:0.09000|INC:1|TRUNK:3|PROVIDER:37)
  82. 2024-06-25 07:46:13.472092 [DEBUG] mod_dptools.c:1519 SET sofia/default/27876303987@102.220.232.19 [termination_rates]=[ID:4278012|CODE:^2744873.*|DESTINATION:RSA Telkom Geographic|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:0.09000|INC:1|TRUNK:3|PROVIDER:37]
  83. EXECUTE sofia/default/27876303987@102.220.232.19 export(rtp_append_audio_sdp=a=fmtp:18 annexb=no)
  84. 2024-06-25 07:46:13.472092 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [rtp_append_audio_sdp]=[a=fmtp:18 annexb=no]
  85. EXECUTE sofia/default/27876303987@102.220.232.19 set(absolute_codec_string=^^:G729:PCMA:PCMU)
  86. 2024-06-25 07:46:13.472092 [DEBUG] mod_dptools.c:1519 SET sofia/default/27876303987@102.220.232.19 [absolute_codec_string]=[^^:G729:PCMA:PCMU]
  87. EXECUTE sofia/default/27876303987@102.220.232.19 limit_execute(db Transit_JHB_BRY_SBC gw_Transit_JHB_BRY_SBC 500 bridge {absolute_codec_string=^^:G729:PCMA:PCMU}sofia/gateway/Transit_JHB_BRY_SBC/27448734188)
  88. 2024-06-25 07:46:13.472092 [DEBUG] switch_limit.c:126 incr called: Transit_JHB_BRY_SBC_gw_Transit_JHB_BRY_SBC max:500, interval:0
  89. 2024-06-25 07:46:13.472092 [DEBUG] mod_db.c:194 Usage for Transit_JHB_BRY_SBC_gw_Transit_JHB_BRY_SBC is now 35/500
  90. EXECUTE sofia/default/27876303987@102.220.232.19 bridge({absolute_codec_string=^^:G729:PCMA:PCMU}sofia/gateway/Transit_JHB_BRY_SBC/27448734188)
  91. 2024-06-25 07:46:13.492051 [DEBUG] switch_channel.c:1250 sofia/default/27876303987@102.220.232.19 EXPORTING[export_vars] [t38_passthru]=[true] to event
  92. 2024-06-25 07:46:13.492051 [DEBUG] switch_channel.c:1250 sofia/default/27876303987@102.220.232.19 EXPORTING[export_vars] [rtp_append_audio_sdp]=[a=fmtp:18 annexb=no] to event
  93. 2024-06-25 07:46:13.492051 [DEBUG] switch_ivr_originate.c:2127 Parsing global variables
  94. 2024-06-25 07:46:13.492051 [NOTICE] switch_channel.c:1104 New Channel sofia/default/27448734188 [576446a8-c04a-4717-a207-9096dba23e22]
  95. 2024-06-25 07:46:13.492051 [DEBUG] mod_sofia.c:4813 (sofia/default/27448734188) State Change CS_NEW -> CS_INIT
  96. 2024-06-25 07:46:13.492051 [DEBUG] switch_core_state_machine.c:543 (sofia/default/27448734188) Running State Change CS_INIT
  97. 2024-06-25 07:46:13.492051 [DEBUG] switch_core_state_machine.c:586 (sofia/default/27448734188) State INIT
  98. 2024-06-25 07:46:13.492051 [DEBUG] mod_sofia.c:89 sofia/default/27448734188 SOFIA INIT
  99. 2024-06-25 07:46:13.492051 [DEBUG] sofia_glue.c:1228 sip:196.31.25.91 Setting proxy route to sofia/default/27448734188
  100. 2024-06-25 07:46:13.492051 [DEBUG] sofia_glue.c:1257 sofia/default/27448734188 sending invite version: 1.6.8  64bit
  101. Local SDP:
  102. v=0
  103. o=FreeSWITCH 1719276935 1719276936 IN IP4 196.31.25.87
  104. s=FreeSWITCH
  105. c=IN IP4 196.31.25.87
  106. t=0 0
  107. m=audio 17438 RTP/AVP 18 8 0 101
  108. a=rtpmap:18 G729/8000
  109. a=fmtp:18 annexb=no
  110. a=rtpmap:8 PCMA/8000
  111. a=rtpmap:0 PCMU/8000
  112. a=rtpmap:101 telephone-event/8000
  113. a=fmtp:101 0-16
  114. a=fmtp:18 annexb=no
  115. a=ptime:20
  116. a=sendrecv
  117.  
  118. 2024-06-25 07:46:13.492051 [DEBUG] switch_core_state_machine.c:40 sofia/default/27448734188 Standard INIT
  119. 2024-06-25 07:46:13.492051 [DEBUG] switch_core_state_machine.c:48 (sofia/default/27448734188) State Change CS_INIT -> CS_ROUTING
  120. 2024-06-25 07:46:13.492051 [DEBUG] switch_core_state_machine.c:586 (sofia/default/27448734188) State INIT going to sleep
  121. 2024-06-25 07:46:13.492051 [DEBUG] switch_core_state_machine.c:543 (sofia/default/27448734188) Running State Change CS_ROUTING
  122. 2024-06-25 07:46:13.492051 [DEBUG] sofia.c:6858 Channel sofia/default/27448734188 entering state [calling][0]
  123. 2024-06-25 07:46:13.492051 [DEBUG] switch_core_state_machine.c:602 (sofia/default/27448734188) State ROUTING
  124. 2024-06-25 07:46:13.492051 [DEBUG] mod_sofia.c:142 sofia/default/27448734188 SOFIA ROUTING
  125. 2024-06-25 07:46:13.492051 [DEBUG] switch_ivr_originate.c:67 (sofia/default/27448734188) State Change CS_ROUTING -> CS_CONSUME_MEDIA
  126. 2024-06-25 07:46:13.492051 [DEBUG] switch_core_state_machine.c:602 (sofia/default/27448734188) State ROUTING going to sleep
  127. 2024-06-25 07:46:13.492051 [DEBUG] switch_core_state_machine.c:543 (sofia/default/27448734188) Running State Change CS_CONSUME_MEDIA
  128. 2024-06-25 07:46:13.492051 [DEBUG] switch_core_state_machine.c:621 (sofia/default/27448734188) State CONSUME_MEDIA
  129. 2024-06-25 07:46:13.492051 [DEBUG] switch_core_state_machine.c:621 (sofia/default/27448734188) State CONSUME_MEDIA going to sleep
  130. 2024-06-25 07:46:13.792066 [WARNING] sofia_reg.c:2889 Can't find user [27106300711@196.31.25.87] from 196.31.25.91
  131. You must define a domain called '196.31.25.87' in your directory and add a user with the id="27106300711" attribute
  132. and you must configure your device to use the proper domain in it's authentication credentials.
  133. 2024-06-25 07:46:13.812086 [WARNING] sofia_reg.c:2889 Can't find user [27106300712@196.31.25.87] from 196.31.25.91
  134. You must define a domain called '196.31.25.87' in your directory and add a user with the id="27106300712" attribute
  135. and you must configure your device to use the proper domain in it's authentication credentials.
  136. 2024-06-25 07:46:14.272093 [WARNING] sofia_reg.c:2889 Can't find user [27106300717@196.31.25.87] from 196.31.25.91
  137. You must define a domain called '196.31.25.87' in your directory and add a user with the id="27106300717" attribute
  138. and you must configure your device to use the proper domain in it's authentication credentials.
  139. 2024-06-25 07:46:15.912069 [DEBUG] sofia.c:6858 Channel sofia/default/27448734188 entering state [proceeding][180]
  140. 2024-06-25 07:46:15.912069 [DEBUG] sofia.c:6868 Remote SDP:
  141. v=0
  142. o=PortaSIP 4084356539596529243 1 IN IP4 197.97.67.168
  143. s=-
  144. t=0 0
  145. m=audio 21386 RTP/AVP 18 101
  146. c=IN IP4 197.97.67.168
  147. a=rtpmap:18 G729/8000
  148. a=fmtp:18 annexb=no
  149. a=rtpmap:101 telephone-event/8000
  150. a=ptime:20
  151.  
  152. 2024-06-25 07:46:15.912069 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [G729:18:8000:20:8000:1]/[G729:18:8000:20:8000:1]
  153. 2024-06-25 07:46:15.912069 [DEBUG] switch_core_media.c:4410 Audio Codec Compare [G729:18:8000:20:8000:1] ++++ is saved as a match
  154. 2024-06-25 07:46:15.912069 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
  155. 2024-06-25 07:46:15.912069 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
  156. 2024-06-25 07:46:15.912069 [DEBUG] switch_core_media.c:4271 Set telephone-event payload to 101@8000
  157. 2024-06-25 07:46:15.912069 [DEBUG] switch_core_media.c:3090 Set Codec sofia/default/27448734188 G729/8000 20 ms 160 samples 8000 bits 1 channels
  158. 2024-06-25 07:46:15.912069 [DEBUG] switch_core_codec.c:111 sofia/default/27448734188 Original read codec set to G729:18
  159. 2024-06-25 07:46:15.912069 [DEBUG] switch_core_media.c:4623 Set telephone-event payload to 101@8000
  160. 2024-06-25 07:46:15.912069 [DEBUG] switch_core_media.c:4681 sofia/default/27448734188 Set 2833 dtmf send payload to 101 recv payload to 101
  161. 2024-06-25 07:46:15.912069 [DEBUG] switch_core_media.c:6464 AUDIO RTP [sofia/default/27448734188] 196.31.25.87 port 17438 -> 197.97.67.168 port 21386 codec: 18 ms: 20
  162. 2024-06-25 07:46:15.912069 [DEBUG] switch_rtp.c:3832 Starting timer [soft] 160 bytes per 20ms
  163. 2024-06-25 07:46:15.912069 [DEBUG] switch_core_media.c:6763 sofia/default/27448734188 Set 2833 dtmf send payload to 101
  164. 2024-06-25 07:46:15.912069 [DEBUG] switch_core_media.c:6770 sofia/default/27448734188 Set 2833 dtmf receive payload to 101
  165. 2024-06-25 07:46:15.912069 [DEBUG] switch_core_media.c:6793 sofia/default/27448734188 Set rtp dtmf delay to 40
  166. 2024-06-25 07:46:15.912069 [NOTICE] sofia_media.c:92 Pre-Answer sofia/default/27448734188!
  167. 2024-06-25 07:46:15.912069 [DEBUG] switch_channel.c:3471 (sofia/default/27448734188) Callstate Change DOWN -> EARLY
  168. 2024-06-25 07:46:15.912069 [INFO] switch_ivr_originate.c:3556 Sending early media
  169. 2024-06-25 07:46:15.912069 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G729:18:8000:20:8000:1]
  170. 2024-06-25 07:46:15.912069 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  171. 2024-06-25 07:46:15.912069 [DEBUG] switch_core_media.c:4410 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
  172. 2024-06-25 07:46:15.912069 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  173. 2024-06-25 07:46:15.912069 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G729:18:8000:20:8000:1]
  174. 2024-06-25 07:46:15.912069 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  175. 2024-06-25 07:46:15.912069 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  176. 2024-06-25 07:46:15.912069 [DEBUG] switch_core_media.c:4410 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
  177. 2024-06-25 07:46:15.912069 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [G729:18:8000:20:8000:1]/[G729:18:8000:20:8000:1]
  178. 2024-06-25 07:46:15.912069 [DEBUG] switch_core_media.c:4410 Audio Codec Compare [G729:18:8000:20:8000:1] ++++ is saved as a match
  179. 2024-06-25 07:46:15.912069 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
  180. 2024-06-25 07:46:15.912069 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
  181. 2024-06-25 07:46:15.912069 [DEBUG] switch_core_media.c:4271 Set telephone-event payload to 101@8000
  182. 2024-06-25 07:46:15.912069 [DEBUG] switch_core_media.c:3090 Set Codec sofia/default/27876303987@102.220.232.19 PCMA/8000 20 ms 160 samples 64000 bits 1 channels
  183. 2024-06-25 07:46:15.912069 [DEBUG] switch_core_codec.c:111 sofia/default/27876303987@102.220.232.19 Original read codec set to PCMA:8
  184. 2024-06-25 07:46:15.912069 [DEBUG] switch_core_media.c:4623 Set telephone-event payload to 101@8000
  185. 2024-06-25 07:46:15.912069 [DEBUG] switch_core_media.c:4681 sofia/default/27876303987@102.220.232.19 Set 2833 dtmf send payload to 101 recv payload to 101
  186. 2024-06-25 07:46:15.912069 [DEBUG] switch_core_media.c:6464 AUDIO RTP [sofia/default/27876303987@102.220.232.19] 196.31.25.87 port 31202 -> 102.220.232.19 port 23228 codec: 8 ms: 20
  187. 2024-06-25 07:46:15.912069 [DEBUG] switch_rtp.c:3832 Starting timer [soft] 160 bytes per 20ms
  188. 2024-06-25 07:46:15.912069 [DEBUG] switch_core_media.c:6763 sofia/default/27876303987@102.220.232.19 Set 2833 dtmf send payload to 101
  189. 2024-06-25 07:46:15.912069 [DEBUG] switch_core_media.c:6770 sofia/default/27876303987@102.220.232.19 Set 2833 dtmf receive payload to 101
  190. 2024-06-25 07:46:15.912069 [DEBUG] switch_core_media.c:6793 sofia/default/27876303987@102.220.232.19 Set rtp dtmf delay to 40
  191. 2024-06-25 07:46:15.912069 [NOTICE] sofia_media.c:92 Pre-Answer sofia/default/27876303987@102.220.232.19!
  192. 2024-06-25 07:46:15.912069 [DEBUG] switch_channel.c:3471 (sofia/default/27876303987@102.220.232.19) Callstate Change RINGING -> EARLY
  193. 2024-06-25 07:46:15.912069 [DEBUG] mod_sofia.c:2367 Ring SDP:
  194. v=0
  195. o=FreeSWITCH 1719263173 1719263174 IN IP4 196.31.25.87
  196. s=FreeSWITCH
  197. c=IN IP4 196.31.25.87
  198. t=0 0
  199. m=audio 31202 RTP/AVP 8 101
  200. a=rtpmap:8 PCMA/8000
  201. a=rtpmap:101 telephone-event/8000
  202. a=fmtp:101 0-16
  203. a=fmtp:18 annexb=no
  204. a=ptime:20
  205. a=sendrecv
  206.  
  207. 2024-06-25 07:46:15.912069 [DEBUG] switch_ivr_originate.c:3607 Originate Resulted in Success: [sofia/default/27448734188]
  208. 2024-06-25 07:46:15.932067 [DEBUG] switch_ivr_bridge.c:1594 (sofia/default/27448734188) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
  209. 2024-06-25 07:46:15.932067 [DEBUG] switch_core_state_machine.c:543 (sofia/default/27448734188) Running State Change CS_EXCHANGE_MEDIA
  210. 2024-06-25 07:46:15.932067 [DEBUG] switch_core_state_machine.c:612 (sofia/default/27448734188) State EXCHANGE_MEDIA
  211. 2024-06-25 07:46:15.932067 [DEBUG] mod_sofia.c:628 SOFIA EXCHANGE_MEDIA
  212. 2024-06-25 07:46:15.972071 [DEBUG] switch_rtp.c:6707 Correct audio ip/port confirmed.
  213. 2024-06-25 07:46:16.152069 [NOTICE] switch_channel.c:1104 New Channel sofia/default/27118921900@gtsbc.goldtelcloud.co.za [74499757-c593-4a47-ba77-ea6a410b52f2]
  214. 2024-06-25 07:46:16.152069 [DEBUG] switch_core_state_machine.c:543 (sofia/default/27118921900@gtsbc.goldtelcloud.co.za) Running State Change CS_NEW
  215. 2024-06-25 07:46:16.152069 [DEBUG] sofia.c:9376 sofia/default/27118921900@gtsbc.goldtelcloud.co.za receiving invite from 196.31.25.91:5060 version: 1.6.8  64bit
  216. 2024-06-25 07:46:16.152069 [DEBUG] sofia.c:9498 1 acls to check for proxy
  217. 2024-06-25 07:46:16.152069 [DEBUG] sofia.c:9503 checking 196.31.25.91 against acl proxy_acl
  218. 2024-06-25 07:46:16.152069 [INFO] sofia.c:9505 196.31.25.91 is a proxy according to the proxy_acl acl
  219. 2024-06-25 07:46:16.152069 [DEBUG] sofia.c:9515 network ip is a proxy
  220. 2024-06-25 07:46:16.152069 [DEBUG] sofia.c:9519 found auth ip [X-AUTH-IP] header of [41.4.17.223]
  221. 2024-06-25 07:46:16.152069 [DEBUG] sofia.c:9543 IP 196.31.25.91 Rejected by acl "default". Falling back to Digest auth.
  222. 2024-06-25 07:46:16.152069 [DEBUG] switch_core_state_machine.c:562 (sofia/default/27118921900@gtsbc.goldtelcloud.co.za) State NEW
  223. 2024-06-25 07:46:16.252068 [DEBUG] sofia.c:2214 detaching session 74499757-c593-4a47-ba77-ea6a410b52f2
  224. 2024-06-25 07:46:16.252068 [DEBUG] sofia.c:6858 Channel sofia/default/27876303987@102.220.232.19 entering state [early][183]
  225. 2024-06-25 07:46:16.292077 [DEBUG] sofia.c:2322 Re-attaching to session 74499757-c593-4a47-ba77-ea6a410b52f2
  226. 2024-06-25 07:46:16.292077 [DEBUG] sofia.c:9376 sofia/default/27118921900@gtsbc.goldtelcloud.co.za receiving invite from 196.31.25.91:5060 version: 1.6.8  64bit
  227. 2024-06-25 07:46:16.292077 [DEBUG] sofia.c:9498 1 acls to check for proxy
  228. 2024-06-25 07:46:16.292077 [DEBUG] sofia.c:9503 checking 196.31.25.91 against acl proxy_acl
  229. 2024-06-25 07:46:16.292077 [INFO] sofia.c:9505 196.31.25.91 is a proxy according to the proxy_acl acl
  230. 2024-06-25 07:46:16.292077 [DEBUG] sofia.c:9515 network ip is a proxy
  231. 2024-06-25 07:46:16.292077 [DEBUG] sofia.c:9519 found auth ip [X-AUTH-IP] header of [41.4.17.223]
  232. 2024-06-25 07:46:16.292077 [DEBUG] sofia.c:9543 IP 196.31.25.91 Rejected by acl "default". Falling back to Digest auth.
  233. 2024-06-25 07:46:16.312090 [DEBUG] sofia.c:6858 Channel sofia/default/27118921900@gtsbc.goldtelcloud.co.za entering state [received][100]
  234. 2024-06-25 07:46:16.312090 [DEBUG] sofia.c:6868 Remote SDP:
  235. v=0
  236. o=DinStar 2038805052 1099526049 IN IP4 41.4.17.223
  237. s=-
  238. c=IN IP4 41.4.17.223
  239. t=0 0
  240. m=audio 8012 RTP/AVP 18 0 8 101
  241. a=rtpmap:18 G729/8000
  242. a=fmtp:18 annexb=no
  243. a=rtpmap:0 PCMU/8000
  244. a=rtpmap:8 PCMA/8000
  245. a=rtpmap:101 telephone-event/8000
  246. a=fmtp:101 0-15
  247. a=ptime:20
  248. a=oldoip:10.0.0.250
  249. a=oldcip:10.0.0.250
  250.  
  251. 2024-06-25 07:46:16.312090 [DEBUG] sofia.c:7227 (sofia/default/27118921900@gtsbc.goldtelcloud.co.za) State Change CS_NEW -> CS_INIT
  252. 2024-06-25 07:46:16.312090 [DEBUG] switch_core_state_machine.c:543 (sofia/default/27118921900@gtsbc.goldtelcloud.co.za) Running State Change CS_INIT
  253. 2024-06-25 07:46:16.312090 [DEBUG] switch_core_state_machine.c:586 (sofia/default/27118921900@gtsbc.goldtelcloud.co.za) State INIT
  254. 2024-06-25 07:46:16.312090 [DEBUG] mod_sofia.c:89 sofia/default/27118921900@gtsbc.goldtelcloud.co.za SOFIA INIT
  255. 2024-06-25 07:46:16.312090 [DEBUG] switch_core_state_machine.c:40 sofia/default/27118921900@gtsbc.goldtelcloud.co.za Standard INIT
  256. 2024-06-25 07:46:16.312090 [DEBUG] switch_core_state_machine.c:48 (sofia/default/27118921900@gtsbc.goldtelcloud.co.za) State Change CS_INIT -> CS_ROUTING
  257. 2024-06-25 07:46:16.312090 [DEBUG] switch_core_state_machine.c:586 (sofia/default/27118921900@gtsbc.goldtelcloud.co.za) State INIT going to sleep
  258. 2024-06-25 07:46:16.312090 [DEBUG] switch_core_state_machine.c:543 (sofia/default/27118921900@gtsbc.goldtelcloud.co.za) Running State Change CS_ROUTING
  259. 2024-06-25 07:46:16.312090 [DEBUG] switch_channel.c:2249 (sofia/default/27118921900@gtsbc.goldtelcloud.co.za) Callstate Change DOWN -> RINGING
  260. 2024-06-25 07:46:16.312090 [DEBUG] switch_core_state_machine.c:602 (sofia/default/27118921900@gtsbc.goldtelcloud.co.za) State ROUTING
  261. 2024-06-25 07:46:16.312090 [DEBUG] mod_sofia.c:142 sofia/default/27118921900@gtsbc.goldtelcloud.co.za SOFIA ROUTING
  262. 2024-06-25 07:46:16.312090 [DEBUG] switch_core_state_machine.c:236 sofia/default/27118921900@gtsbc.goldtelcloud.co.za Standard ROUTING
  263. 2024-06-25 07:46:16.312090 [INFO] mod_dialplan_xml.c:637 Processing 27118921900 <27118921900>->0119751588 in context default
  264. 2024-06-25 07:46:18.092129 [NOTICE] sofia.c:988 Hangup sofia/default/27446913718@gtsbc.goldtelcloud.co.za [CS_EXECUTE] [NORMAL_CLEARING]
  265. 2024-06-25 07:46:18.092129 [DEBUG] switch_ivr_bridge.c:701 sofia/default/27446913718@gtsbc.goldtelcloud.co.za ending bridge by request from write function
  266. 2024-06-25 07:46:18.092129 [DEBUG] switch_ivr_bridge.c:780 BRIDGE THREAD DONE [sofia/default/27446019550]
  267. 2024-06-25 07:46:18.092129 [NOTICE] switch_ivr_bridge.c:884 Hangup sofia/default/27446019550 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING]
  268. 2024-06-25 07:46:18.092129 [DEBUG] switch_core_state_machine.c:612 (sofia/default/27446019550) State EXCHANGE_MEDIA going to sleep
  269. 2024-06-25 07:46:18.092129 [DEBUG] switch_core_state_machine.c:543 (sofia/default/27446019550) Running State Change CS_HANGUP
  270. 2024-06-25 07:46:18.092129 [DEBUG] switch_core_state_machine.c:809 (sofia/default/27446019550) Callstate Change ACTIVE -> HANGUP
  271. 2024-06-25 07:46:18.092129 [DEBUG] switch_ivr_bridge.c:780 BRIDGE THREAD DONE [sofia/default/27446913718@gtsbc.goldtelcloud.co.za]
  272. 2024-06-25 07:46:18.092129 [DEBUG] switch_core_state_machine.c:811 (sofia/default/27446019550) State HANGUP
  273. 2024-06-25 07:46:18.092129 [DEBUG] mod_sofia.c:431 sofia/default/27446019550 Overriding SIP cause 480 with 200 from the other leg
  274. 2024-06-25 07:46:18.092129 [DEBUG] mod_sofia.c:437 Channel sofia/default/27446019550 hanging up, cause: NORMAL_CLEARING
  275. 2024-06-25 07:46:18.092129 [DEBUG] switch_ivr_bridge.c:1692 sofia/default/27446019550 skip receive message [UNBRIDGE] (channel is hungup already)
  276. 2024-06-25 07:46:18.092129 [DEBUG] switch_ivr_bridge.c:1695 sofia/default/27446913718@gtsbc.goldtelcloud.co.za skip receive message [UNBRIDGE] (channel is hungup already)
  277. 2024-06-25 07:46:18.092129 [DEBUG] switch_core_session.c:2796 sofia/default/27446913718@gtsbc.goldtelcloud.co.za skip receive message [PHONE_EVENT] (channel is hungup already)
  278. 2024-06-25 07:46:18.092129 [DEBUG] mod_sofia.c:490 Sending BYE to sofia/default/27446019550
  279. 2024-06-25 07:46:18.092129 [DEBUG] switch_core_state_machine.c:60 sofia/default/27446019550 Standard HANGUP, cause: NORMAL_CLEARING
  280. 2024-06-25 07:46:18.092129 [DEBUG] switch_core_state_machine.c:811 (sofia/default/27446019550) State HANGUP going to sleep
  281. 2024-06-25 07:46:18.092129 [DEBUG] switch_core_session.c:2796 sofia/default/27446913718@gtsbc.goldtelcloud.co.za skip receive message [PHONE_EVENT] (channel is hungup already)
  282. 2024-06-25 07:46:18.092129 [DEBUG] switch_core_state_machine.c:609 (sofia/default/27446913718@gtsbc.goldtelcloud.co.za) State EXECUTE going to sleep
  283. 2024-06-25 07:46:18.092129 [DEBUG] switch_core_state_machine.c:543 (sofia/default/27446913718@gtsbc.goldtelcloud.co.za) Running State Change CS_HANGUP
  284. 2024-06-25 07:46:18.092129 [DEBUG] switch_core_state_machine.c:578 (sofia/default/27446019550) State Change CS_HANGUP -> CS_REPORTING
  285. 2024-06-25 07:46:18.092129 [DEBUG] switch_core_state_machine.c:543 (sofia/default/27446019550) Running State Change CS_REPORTING
  286. 2024-06-25 07:46:18.092129 [DEBUG] switch_core_state_machine.c:897 (sofia/default/27446019550) State REPORTING
  287. 2024-06-25 07:46:18.092129 [DEBUG] switch_core_state_machine.c:809 (sofia/default/27446913718@gtsbc.goldtelcloud.co.za) Callstate Change ACTIVE -> HANGUP
  288. 2024-06-25 07:46:18.092129 [DEBUG] switch_core_state_machine.c:811 (sofia/default/27446913718@gtsbc.goldtelcloud.co.za) State HANGUP
  289. 2024-06-25 07:46:18.092129 [DEBUG] mod_sofia.c:437 Channel sofia/default/27446913718@gtsbc.goldtelcloud.co.za hanging up, cause: NORMAL_CLEARING
  290. 2024-06-25 07:46:18.092129 [DEBUG] switch_core_state_machine.c:60 sofia/default/27446913718@gtsbc.goldtelcloud.co.za Standard HANGUP, cause: NORMAL_CLEARING
  291. 2024-06-25 07:46:18.092129 [DEBUG] switch_core_state_machine.c:811 (sofia/default/27446913718@gtsbc.goldtelcloud.co.za) State HANGUP going to sleep
  292. 2024-06-25 07:46:18.092129 [DEBUG] switch_core_state_machine.c:578 (sofia/default/27446913718@gtsbc.goldtelcloud.co.za) State Change CS_HANGUP -> CS_REPORTING
  293. 2024-06-25 07:46:18.092129 [DEBUG] switch_core_state_machine.c:543 (sofia/default/27446913718@gtsbc.goldtelcloud.co.za) Running State Change CS_REPORTING
  294. 2024-06-25 07:46:18.092129 [DEBUG] switch_core_state_machine.c:897 (sofia/default/27446913718@gtsbc.goldtelcloud.co.za) State REPORTING
  295. Dialplan: sofia/default/27118921900@gtsbc.goldtelcloud.co.za parsing [default->] continue=false
  296. Dialplan: sofia/default/27118921900@gtsbc.goldtelcloud.co.za Regex (PASS) [] destination_number(0119751588) =~ // break=on-false
  297. Dialplan: sofia/default/27118921900@gtsbc.goldtelcloud.co.za Action set(callstart=2024-06-25 05:46:18)
  298. Dialplan: sofia/default/27118921900@gtsbc.goldtelcloud.co.za Action set(call_processed=internal)
  299. Dialplan: sofia/default/27118921900@gtsbc.goldtelcloud.co.za Action set(originated_destination_number=27119751588)
  300. Dialplan: sofia/default/27118921900@gtsbc.goldtelcloud.co.za Action set(hangup_after_bridge=true)
  301. Dialplan: sofia/default/27118921900@gtsbc.goldtelcloud.co.za Action set(continue_on_fail=true)
  302. Dialplan: sofia/default/27118921900@gtsbc.goldtelcloud.co.za Action set(fax_enable_t38=true)
  303. Dialplan: sofia/default/27118921900@gtsbc.goldtelcloud.co.za Action set(fax_enable_t38_request=true)
  304. Dialplan: sofia/default/27118921900@gtsbc.goldtelcloud.co.za Action export(t38_passthru=true)
  305. Dialplan: sofia/default/27118921900@gtsbc.goldtelcloud.co.za Action set(accountid=881)
  306. Dialplan: sofia/default/27118921900@gtsbc.goldtelcloud.co.za Action set(account_type=0)
  307. Dialplan: sofia/default/27118921900@gtsbc.goldtelcloud.co.za Action set(resellerid=61)
  308. Dialplan: sofia/default/27118921900@gtsbc.goldtelcloud.co.za Action set(accountcode=4463339454)
  309. Dialplan: sofia/default/27118921900@gtsbc.goldtelcloud.co.za Action set(call_direction=outbound)
  310. Dialplan: sofia/default/27118921900@gtsbc.goldtelcloud.co.za Action set(calltype=STANDARD)
  311. Dialplan: sofia/default/27118921900@gtsbc.goldtelcloud.co.za Action sched_hangup(+5400 allotted_timeout)
  312. Dialplan: sofia/default/27118921900@gtsbc.goldtelcloud.co.za Action log(INFO [Customer info] : [Account code: 4463339454, Rategroup Id: 201, Called number: 0119751588])
  313. Dialplan: sofia/default/27118921900@gtsbc.goldtelcloud.co.za Action log(INFO Reseller cost = 0.28050 and customer cost is 0.33000 and reseller max length = 90.0000)
  314. Dialplan: sofia/default/27118921900@gtsbc.goldtelcloud.co.za Action set(origination_rates=ID:353162311|CODE:^2711975.*|DESTINATION:RSA Telkom Geographic|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:0.33000|INC:1|RATEGROUP:201|MARKUP:0|ACCID:881||ID:350165786|CODE:^2711975.*|DESTINATION:RSA Telkom Geographic|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:0.28050|INC:1|RATEGROUP:190|MARKUP:0|ACCID:61)
  315. Dialplan: sofia/default/27118921900@gtsbc.goldtelcloud.co.za Action limit(db 4463339454 db_4463339454 6/1)
  316. Dialplan: sofia/default/27118921900@gtsbc.goldtelcloud.co.za Action set(effective_destination_number=0119751588)
  317. Dialplan: sofia/default/27118921900@gtsbc.goldtelcloud.co.za Action set(termination_rates=ID:4281035|CODE:^2711975.*|DESTINATION:RSA Telkom Geographic|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:0.09000|INC:1|TRUNK:3|PROVIDER:37)
  318. Dialplan: sofia/default/27118921900@gtsbc.goldtelcloud.co.za Action export(rtp_append_audio_sdp=a=fmtp:18 annexb=no)
  319. Dialplan: sofia/default/27118921900@gtsbc.goldtelcloud.co.za Action set(absolute_codec_string=^^:G729:PCMA:PCMU)
  320. Dialplan: sofia/default/27118921900@gtsbc.goldtelcloud.co.za Action limit_execute(db Transit_JHB_BRY_SBC gw_Transit_JHB_BRY_SBC 500 bridge {absolute_codec_string=^^:G729:PCMA:PCMU}sofia/gateway/Transit_JHB_BRY_SBC/27119751588)
  321. Dialplan: sofia/default/27118921900@gtsbc.goldtelcloud.co.za Action bridge(sofia/gateway/Transit_JHB_PKL_SBC/27119751588)
  322. Dialplan: sofia/default/27118921900@gtsbc.goldtelcloud.co.za Action bridge(sofia/gateway/Transit_CPT_BREE_SBC/27119751588)
  323. Dialplan: sofia/default/27118921900@gtsbc.goldtelcloud.co.za Action set(effective_destination_number=0119751588)
  324. Dialplan: sofia/default/27118921900@gtsbc.goldtelcloud.co.za Action set(termination_rates=ID:4296420|CODE:^271197.*|DESTINATION:RSA Telkom Geographic|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:0.09000|INC:1|TRUNK:3|PROVIDER:37)
  325. Dialplan: sofia/default/27118921900@gtsbc.goldtelcloud.co.za Action export(rtp_append_audio_sdp=a=fmtp:18 annexb=no)
  326. Dialplan: sofia/default/27118921900@gtsbc.goldtelcloud.co.za Action set(absolute_codec_string=^^:G729:PCMA:PCMU)
  327. Dialplan: sofia/default/27118921900@gtsbc.goldtelcloud.co.za Action limit_execute(db Transit_JHB_BRY_SBC gw_Transit_JHB_BRY_SBC 500 bridge {absolute_codec_string=^^:G729:PCMA:PCMU}sofia/gateway/Transit_JHB_BRY_SBC/27119751588)
  328. Dialplan: sofia/default/27118921900@gtsbc.goldtelcloud.co.za Action bridge(sofia/gateway/Transit_JHB_PKL_SBC/27119751588)
  329. Dialplan: sofia/default/27118921900@gtsbc.goldtelcloud.co.za Action bridge(sofia/gateway/Transit_CPT_BREE_SBC/27119751588)
  330. 2024-06-25 07:46:18.152088 [DEBUG] switch_core_state_machine.c:286 (sofia/default/27118921900@gtsbc.goldtelcloud.co.za) State Change CS_ROUTING -> CS_EXECUTE
  331. 2024-06-25 07:46:18.152088 [DEBUG] switch_core_state_machine.c:602 (sofia/default/27118921900@gtsbc.goldtelcloud.co.za) State ROUTING going to sleep
  332. 2024-06-25 07:46:18.152088 [DEBUG] switch_core_state_machine.c:543 (sofia/default/27118921900@gtsbc.goldtelcloud.co.za) Running State Change CS_EXECUTE
  333. 2024-06-25 07:46:18.152088 [DEBUG] switch_core_state_machine.c:609 (sofia/default/27118921900@gtsbc.goldtelcloud.co.za) State EXECUTE
  334. 2024-06-25 07:46:18.152088 [DEBUG] mod_sofia.c:197 sofia/default/27118921900@gtsbc.goldtelcloud.co.za SOFIA EXECUTE
  335. 2024-06-25 07:46:18.152088 [DEBUG] switch_core_state_machine.c:328 sofia/default/27118921900@gtsbc.goldtelcloud.co.za Standard EXECUTE
  336. EXECUTE sofia/default/27118921900@gtsbc.goldtelcloud.co.za set(callstart=2024-06-25 05:46:18)
  337. 2024-06-25 07:46:18.152088 [DEBUG] mod_dptools.c:1519 SET sofia/default/27118921900@gtsbc.goldtelcloud.co.za [callstart]=[2024-06-25 05:46:18]
  338. EXECUTE sofia/default/27118921900@gtsbc.goldtelcloud.co.za set(call_processed=internal)
  339. 2024-06-25 07:46:18.152088 [DEBUG] mod_dptools.c:1519 SET sofia/default/27118921900@gtsbc.goldtelcloud.co.za [call_processed]=[internal]
  340. EXECUTE sofia/default/27118921900@gtsbc.goldtelcloud.co.za set(originated_destination_number=27119751588)
  341. 2024-06-25 07:46:18.152088 [DEBUG] mod_dptools.c:1519 SET sofia/default/27118921900@gtsbc.goldtelcloud.co.za [originated_destination_number]=[27119751588]
  342. EXECUTE sofia/default/27118921900@gtsbc.goldtelcloud.co.za set(hangup_after_bridge=true)
  343. 2024-06-25 07:46:18.152088 [DEBUG] mod_dptools.c:1519 SET sofia/default/27118921900@gtsbc.goldtelcloud.co.za [hangup_after_bridge]=[true]
  344. EXECUTE sofia/default/27118921900@gtsbc.goldtelcloud.co.za set(continue_on_fail=true)
  345. 2024-06-25 07:46:18.152088 [DEBUG] mod_dptools.c:1519 SET sofia/default/27118921900@gtsbc.goldtelcloud.co.za [continue_on_fail]=[true]
  346. EXECUTE sofia/default/27118921900@gtsbc.goldtelcloud.co.za set(fax_enable_t38=true)
  347. 2024-06-25 07:46:18.152088 [DEBUG] mod_dptools.c:1519 SET sofia/default/27118921900@gtsbc.goldtelcloud.co.za [fax_enable_t38]=[true]
  348. EXECUTE sofia/default/27118921900@gtsbc.goldtelcloud.co.za set(fax_enable_t38_request=true)
  349. 2024-06-25 07:46:18.152088 [DEBUG] mod_dptools.c:1519 SET sofia/default/27118921900@gtsbc.goldtelcloud.co.za [fax_enable_t38_request]=[true]
  350. EXECUTE sofia/default/27118921900@gtsbc.goldtelcloud.co.za export(t38_passthru=true)
  351. 2024-06-25 07:46:18.152088 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [t38_passthru]=[true]
  352. EXECUTE sofia/default/27118921900@gtsbc.goldtelcloud.co.za set(accountid=881)
  353. 2024-06-25 07:46:18.152088 [DEBUG] mod_dptools.c:1519 SET sofia/default/27118921900@gtsbc.goldtelcloud.co.za [accountid]=[881]
  354. EXECUTE sofia/default/27118921900@gtsbc.goldtelcloud.co.za set(account_type=0)
  355. 2024-06-25 07:46:18.152088 [DEBUG] mod_dptools.c:1519 SET sofia/default/27118921900@gtsbc.goldtelcloud.co.za [account_type]=[0]
  356. EXECUTE sofia/default/27118921900@gtsbc.goldtelcloud.co.za set(resellerid=61)
  357. 2024-06-25 07:46:18.152088 [DEBUG] mod_dptools.c:1519 SET sofia/default/27118921900@gtsbc.goldtelcloud.co.za [resellerid]=[61]
  358. EXECUTE sofia/default/27118921900@gtsbc.goldtelcloud.co.za set(accountcode=4463339454)
  359. 2024-06-25 07:46:18.152088 [DEBUG] mod_dptools.c:1519 SET sofia/default/27118921900@gtsbc.goldtelcloud.co.za [accountcode]=[4463339454]
  360. EXECUTE sofia/default/27118921900@gtsbc.goldtelcloud.co.za set(call_direction=outbound)
  361. 2024-06-25 07:46:18.152088 [DEBUG] mod_dptools.c:1519 SET sofia/default/27118921900@gtsbc.goldtelcloud.co.za [call_direction]=[outbound]
  362. EXECUTE sofia/default/27118921900@gtsbc.goldtelcloud.co.za set(calltype=STANDARD)
  363. 2024-06-25 07:46:18.152088 [DEBUG] mod_dptools.c:1519 SET sofia/default/27118921900@gtsbc.goldtelcloud.co.za [calltype]=[STANDARD]
  364. EXECUTE sofia/default/27118921900@gtsbc.goldtelcloud.co.za sched_hangup(+5400 allotted_timeout)
  365. 2024-06-25 07:46:18.152088 [DEBUG] switch_scheduler.c:249 Added task 2738362 switch_ivr_schedule_hangup (74499757-c593-4a47-ba77-ea6a410b52f2) to run at 1719299778
  366. EXECUTE sofia/default/27118921900@gtsbc.goldtelcloud.co.za log(INFO [Customer info] : [Account code: 4463339454, Rategroup Id: 201, Called number: 0119751588])
  367. 2024-06-25 07:46:18.152088 [INFO] mod_dptools.c:1713 [Customer info] : [Account code: 4463339454, Rategroup Id: 201, Called number: 0119751588]
  368. EXECUTE sofia/default/27118921900@gtsbc.goldtelcloud.co.za log(INFO Reseller cost = 0.28050 and customer cost is 0.33000 and reseller max length = 90.0000)
  369. 2024-06-25 07:46:18.152088 [INFO] mod_dptools.c:1713 Reseller cost = 0.28050 and customer cost is 0.33000 and reseller max length = 90.0000
  370. EXECUTE sofia/default/27118921900@gtsbc.goldtelcloud.co.za set(origination_rates=ID:353162311|CODE:^2711975.*|DESTINATION:RSA Telkom Geographic|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:0.33000|INC:1|RATEGROUP:201|MARKUP:0|ACCID:881||ID:350165786|CODE:^2711975.*|DESTINATION:RSA Telkom Geographic|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:0.28050|INC:1|RATEGROUP:190|MARKUP:0|ACCID:61)
  371. 2024-06-25 07:46:18.152088 [DEBUG] mod_dptools.c:1519 SET sofia/default/27118921900@gtsbc.goldtelcloud.co.za [origination_rates]=[ID:353162311|CODE:^2711975.*|DESTINATION:RSA Telkom Geographic|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:0.33000|INC:1|RATEGROUP:201|MARKUP:0|ACCID:881||ID:350165786|CODE:^2711975.*|DESTINATION:RSA Telkom Geographic|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:0.28050|INC:1|RATEGROUP:190|MARKUP:0|ACCID:61]
  372. EXECUTE sofia/default/27118921900@gtsbc.goldtelcloud.co.za limit(db 4463339454 db_4463339454 6/1)
  373. 2024-06-25 07:46:18.152088 [DEBUG] switch_limit.c:126 incr called: 4463339454_db_4463339454 max:6, interval:1
  374. 2024-06-25 07:46:18.152088 [DEBUG] mod_db.c:194 Usage for 4463339454_db_4463339454 is now 1/6
  375. EXECUTE sofia/default/27118921900@gtsbc.goldtelcloud.co.za set(effective_destination_number=0119751588)
  376. 2024-06-25 07:46:18.152088 [DEBUG] mod_dptools.c:1519 SET sofia/default/27118921900@gtsbc.goldtelcloud.co.za [effective_destination_number]=[0119751588]
  377. EXECUTE sofia/default/27118921900@gtsbc.goldtelcloud.co.za set(termination_rates=ID:4281035|CODE:^2711975.*|DESTINATION:RSA Telkom Geographic|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:0.09000|INC:1|TRUNK:3|PROVIDER:37)
  378. 2024-06-25 07:46:18.172058 [DEBUG] mod_dptools.c:1519 SET sofia/default/27118921900@gtsbc.goldtelcloud.co.za [termination_rates]=[ID:4281035|CODE:^2711975.*|DESTINATION:RSA Telkom Geographic|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:0.09000|INC:1|TRUNK:3|PROVIDER:37]
  379. EXECUTE sofia/default/27118921900@gtsbc.goldtelcloud.co.za export(rtp_append_audio_sdp=a=fmtp:18 annexb=no)
  380. 2024-06-25 07:46:18.172058 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [rtp_append_audio_sdp]=[a=fmtp:18 annexb=no]
  381. EXECUTE sofia/default/27118921900@gtsbc.goldtelcloud.co.za set(absolute_codec_string=^^:G729:PCMA:PCMU)
  382. 2024-06-25 07:46:18.172058 [DEBUG] mod_dptools.c:1519 SET sofia/default/27118921900@gtsbc.goldtelcloud.co.za [absolute_codec_string]=[^^:G729:PCMA:PCMU]
  383. EXECUTE sofia/default/27118921900@gtsbc.goldtelcloud.co.za limit_execute(db Transit_JHB_BRY_SBC gw_Transit_JHB_BRY_SBC 500 bridge {absolute_codec_string=^^:G729:PCMA:PCMU}sofia/gateway/Transit_JHB_BRY_SBC/27119751588)
  384. 2024-06-25 07:46:18.172058 [DEBUG] switch_limit.c:126 incr called: Transit_JHB_BRY_SBC_gw_Transit_JHB_BRY_SBC max:500, interval:0
  385. 2024-06-25 07:46:18.172058 [DEBUG] mod_db.c:194 Usage for Transit_JHB_BRY_SBC_gw_Transit_JHB_BRY_SBC is now 36/500
  386. EXECUTE sofia/default/27118921900@gtsbc.goldtelcloud.co.za bridge({absolute_codec_string=^^:G729:PCMA:PCMU}sofia/gateway/Transit_JHB_BRY_SBC/27119751588)
  387. 2024-06-25 07:46:18.172058 [DEBUG] switch_channel.c:1250 sofia/default/27118921900@gtsbc.goldtelcloud.co.za EXPORTING[export_vars] [t38_passthru]=[true] to event
  388. 2024-06-25 07:46:18.172058 [DEBUG] switch_channel.c:1250 sofia/default/27118921900@gtsbc.goldtelcloud.co.za EXPORTING[export_vars] [rtp_append_audio_sdp]=[a=fmtp:18 annexb=no] to event
  389. 2024-06-25 07:46:18.172058 [DEBUG] switch_ivr_originate.c:2127 Parsing global variables
  390. 2024-06-25 07:46:18.172058 [NOTICE] switch_channel.c:1104 New Channel sofia/default/27119751588 [f6e606dd-d733-440b-9de1-c072a5243b43]
  391. 2024-06-25 07:46:18.172058 [DEBUG] mod_sofia.c:4813 (sofia/default/27119751588) State Change CS_NEW -> CS_INIT
  392. 2024-06-25 07:46:18.172058 [DEBUG] switch_core_state_machine.c:543 (sofia/default/27119751588) Running State Change CS_INIT
  393. 2024-06-25 07:46:18.172058 [DEBUG] switch_core_state_machine.c:586 (sofia/default/27119751588) State INIT
  394. 2024-06-25 07:46:18.172058 [DEBUG] mod_sofia.c:89 sofia/default/27119751588 SOFIA INIT
  395. 2024-06-25 07:46:18.172058 [DEBUG] sofia_glue.c:1228 sip:196.31.25.91 Setting proxy route to sofia/default/27119751588
  396. 2024-06-25 07:46:18.172058 [DEBUG] sofia_glue.c:1257 sofia/default/27119751588 sending invite version: 1.6.8  64bit
  397. Local SDP:
  398. v=0
  399. o=FreeSWITCH 1719275472 1719275473 IN IP4 196.31.25.87
  400. s=FreeSWITCH
  401. c=IN IP4 196.31.25.87
  402. t=0 0
  403. m=audio 18906 RTP/AVP 18 8 0 101
  404. a=rtpmap:18 G729/8000
  405. a=fmtp:18 annexb=no
  406. a=rtpmap:8 PCMA/8000
  407. a=rtpmap:0 PCMU/8000
  408. a=rtpmap:101 telephone-event/8000
  409. a=fmtp:101 0-16
  410. a=fmtp:18 annexb=no
  411. a=ptime:20
  412. a=sendrecv
  413.  
  414. 2024-06-25 07:46:18.172058 [DEBUG] switch_core_state_machine.c:40 sofia/default/27119751588 Standard INIT
  415. 2024-06-25 07:46:18.172058 [DEBUG] switch_core_state_machine.c:48 (sofia/default/27119751588) State Change CS_INIT -> CS_ROUTING
  416. 2024-06-25 07:46:18.172058 [DEBUG] switch_core_state_machine.c:586 (sofia/default/27119751588) State INIT going to sleep
  417. 2024-06-25 07:46:18.172058 [DEBUG] switch_core_state_machine.c:543 (sofia/default/27119751588) Running State Change CS_ROUTING
  418. 2024-06-25 07:46:18.172058 [DEBUG] switch_core_state_machine.c:602 (sofia/default/27119751588) State ROUTING
  419. 2024-06-25 07:46:18.172058 [DEBUG] mod_sofia.c:142 sofia/default/27119751588 SOFIA ROUTING
  420. 2024-06-25 07:46:18.172058 [DEBUG] switch_ivr_originate.c:67 (sofia/default/27119751588) State Change CS_ROUTING -> CS_CONSUME_MEDIA
  421. 2024-06-25 07:46:18.172058 [DEBUG] switch_core_state_machine.c:602 (sofia/default/27119751588) State ROUTING going to sleep
  422. 2024-06-25 07:46:18.172058 [DEBUG] switch_core_state_machine.c:543 (sofia/default/27119751588) Running State Change CS_CONSUME_MEDIA
  423. 2024-06-25 07:46:18.172058 [DEBUG] switch_core_state_machine.c:621 (sofia/default/27119751588) State CONSUME_MEDIA
  424. 2024-06-25 07:46:18.172058 [DEBUG] switch_core_state_machine.c:621 (sofia/default/27119751588) State CONSUME_MEDIA going to sleep
  425. 2024-06-25 07:46:18.272084 [DEBUG] sofia.c:6858 Channel sofia/default/27119751588 entering state [calling][0]
  426. 2024-06-25 07:46:18.412010 [DEBUG] switch_core_state_machine.c:174 sofia/default/27446019550 Standard REPORTING, cause: NORMAL_CLEARING
  427. 2024-06-25 07:46:18.412010 [DEBUG] switch_core_state_machine.c:897 (sofia/default/27446019550) State REPORTING going to sleep
  428. 2024-06-25 07:46:18.412010 [DEBUG] switch_core_state_machine.c:569 (sofia/default/27446019550) State Change CS_REPORTING -> CS_DESTROY
  429. 2024-06-25 07:46:18.412010 [DEBUG] switch_core_session.c:1646 Session 5787226 (sofia/default/27446019550) Locked, Waiting on external entities
  430. 2024-06-25 07:46:18.412010 [NOTICE] switch_core_session.c:1664 Session 5787226 (sofia/default/27446019550) Ended
  431. 2024-06-25 07:46:18.412010 [NOTICE] switch_core_session.c:1668 Close Channel sofia/default/27446019550 [CS_DESTROY]
  432. 2024-06-25 07:46:18.412010 [DEBUG] switch_core_state_machine.c:700 (sofia/default/27446019550) Running State Change CS_DESTROY
  433. 2024-06-25 07:46:18.412010 [DEBUG] switch_core_state_machine.c:710 (sofia/default/27446019550) State DESTROY
  434. 2024-06-25 07:46:18.412010 [DEBUG] mod_sofia.c:342 sofia/default/27446019550 SOFIA DESTROY
  435. 2024-06-25 07:46:18.412010 [DEBUG] switch_core_state_machine.c:181 sofia/default/27446019550 Standard DESTROY
  436. 2024-06-25 07:46:18.412010 [DEBUG] switch_core_state_machine.c:710 (sofia/default/27446019550) State DESTROY going to sleep
  437. 2024-06-25 07:46:18.412010 [DEBUG] switch_core_state_machine.c:174 sofia/default/27446913718@gtsbc.goldtelcloud.co.za Standard REPORTING, cause: NORMAL_CLEARING
  438. 2024-06-25 07:46:18.412010 [DEBUG] switch_core_state_machine.c:897 (sofia/default/27446913718@gtsbc.goldtelcloud.co.za) State REPORTING going to sleep
  439. 2024-06-25 07:46:18.412010 [DEBUG] switch_core_state_machine.c:569 (sofia/default/27446913718@gtsbc.goldtelcloud.co.za) State Change CS_REPORTING -> CS_DESTROY
  440. 2024-06-25 07:46:18.412010 [DEBUG] switch_core_session.c:1646 Session 5787222 (sofia/default/27446913718@gtsbc.goldtelcloud.co.za) Locked, Waiting on external entities
  441. 2024-06-25 07:46:18.412010 [NOTICE] switch_core_session.c:1664 Session 5787222 (sofia/default/27446913718@gtsbc.goldtelcloud.co.za) Ended
  442. 2024-06-25 07:46:18.412010 [NOTICE] switch_core_session.c:1668 Close Channel sofia/default/27446913718@gtsbc.goldtelcloud.co.za [CS_DESTROY]
  443. 2024-06-25 07:46:18.412010 [DEBUG] switch_core_state_machine.c:700 (sofia/default/27446913718@gtsbc.goldtelcloud.co.za) Running State Change CS_DESTROY
  444. 2024-06-25 07:46:18.412010 [DEBUG] switch_core_state_machine.c:710 (sofia/default/27446913718@gtsbc.goldtelcloud.co.za) State DESTROY
  445. 2024-06-25 07:46:18.412010 [DEBUG] mod_sofia.c:342 sofia/default/27446913718@gtsbc.goldtelcloud.co.za SOFIA DESTROY
  446. 2024-06-25 07:46:18.412010 [DEBUG] switch_core_state_machine.c:181 sofia/default/27446913718@gtsbc.goldtelcloud.co.za Standard DESTROY
  447. 2024-06-25 07:46:18.412010 [DEBUG] switch_core_state_machine.c:710 (sofia/default/27446913718@gtsbc.goldtelcloud.co.za) State DESTROY going to sleep
  448. 2024-06-25 07:46:18.652069 [DEBUG] switch_scheduler.c:144 Deleting task 2738357 switch_ivr_schedule_hangup (3f593ecd-f908-498b-a14d-b3db8e87b421)
  449. 2024-06-25 07:46:19.892072 [DEBUG] sofia.c:6858 Channel sofia/default/27119751588 entering state [proceeding][180]
  450. 2024-06-25 07:46:19.892072 [NOTICE] sofia.c:6960 Ring-Ready sofia/default/27119751588!
  451. 2024-06-25 07:46:19.892072 [DEBUG] switch_channel.c:3343 (sofia/default/27119751588) Callstate Change DOWN -> RINGING
  452. 2024-06-25 07:46:19.892072 [NOTICE] mod_sofia.c:2198 Ring-Ready sofia/default/27118921900@gtsbc.goldtelcloud.co.za!
  453. 2024-06-25 07:46:19.892072 [NOTICE] switch_ivr_originate.c:525 Ring Ready sofia/default/27118921900@gtsbc.goldtelcloud.co.za!
  454. 2024-06-25 07:46:20.252071 [DEBUG] sofia.c:6858 Channel sofia/default/27118921900@gtsbc.goldtelcloud.co.za entering state [early][180]
  455. 2024-06-25 07:46:21.292045 [ERR] switch_odbc.c:522 ERR: [insert into sip_registrations (call_id,sip_user,sip_host,presence_hosts,contact,status,rpid,expires,user_agent,server_user,server_host,profile_name,hostname,network_ip,network_port,sip_username,sip_realm,mwi_user,mwi_host, orig_server_host, orig_hostname, sub_host, ping_status, ping_count, force_ping) values ('443e038-5b80a929-20a3-65014-7-71244579-7','27116099000', '196.31.25.87','196.31.25.87,196.31.25.87','"" <sip:27116099000@41.169.128.91:8355;transport=UDP;fs_path=sip%3A196.31.25.91%3Blr%3Breceived%3Dsip%3A41.169.128.91%3A8355>','Registered(UDP)', 'unknown', 1719294501, 'Ericsson-LG Enterprise iPECS-eMG eMG80 3.0.33', '27116099000', '196.31.25.87', 'default', 'gtss2', '196.31.25.91', '5060','27116099000','gtsbc.goldtelcloud.co.za','27116099000','196.31.25.87','196.31.25.87','gtss2','196.31.25.87', 'Reachable', 0, 0)]
  456. [STATE: HY000 CODE 1213 ERROR: [MySQL][ODBC 5.1 Driver][mysqld-5.5.5-10.0.22-MariaDB-0+deb8u1-log]Deadlock found when trying to get lock; try restarting transaction
  457. ]
  458. 2024-06-25 07:46:21.292045 [ERR] switch_core_sqldb.c:587 ODBC SQL ERR [STATE: HY000 CODE 1213 ERROR: [MySQL][ODBC 5.1 Driver][mysqld-5.5.5-10.0.22-MariaDB-0+deb8u1-log]Deadlock found when trying to get lock; try restarting transaction
  459. ]
  460. insert into sip_registrations (call_id,sip_user,sip_host,presence_hosts,contact,status,rpid,expires,user_agent,server_user,server_host,profile_name,hostname,network_ip,network_port,sip_username,sip_realm,mwi_user,mwi_host, orig_server_host, orig_hostname, sub_host, ping_status, ping_count, force_ping) values ('443e038-5b80a929-20a3-65014-7-71244579-7','27116099000', '196.31.25.87','196.31.25.87,196.31.25.87','"" <sip:27116099000@41.169.128.91:8355;transport=UDP;fs_path=sip%3A196.31.25.91%3Blr%3Breceived%3Dsip%3A41.169.128.91%3A8355>','Registered(UDP)', 'unknown', 1719294501, 'Ericsson-LG Enterprise iPECS-eMG eMG80 3.0.33', '27116099000', '196.31.25.87', 'default', 'gtss2', '196.31.25.91', '5060','27116099000','gtsbc.goldtelcloud.co.za','27116099000','196.31.25.87','196.31.25.87','gtss2','196.31.25.87', 'Reachable', 0, 0)
  461. 2024-06-25 07:46:21.292045 [DEBUG] sofia.c:6858 Channel sofia/default/27448734188 entering state [completing][200]
  462. 2024-06-25 07:46:21.292045 [DEBUG] sofia.c:6865 Duplicate SDP
  463. v=0
  464. o=PortaSIP 4084356539596529243 1 IN IP4 197.97.67.168
  465. s=-
  466. t=0 0
  467. m=audio 21386 RTP/AVP 18 101
  468. c=IN IP4 197.97.67.168
  469. a=rtpmap:18 G729/8000
  470. a=fmtp:18 annexb=no
  471. a=rtpmap:101 telephone-event/8000
  472. a=ptime:20
  473.  
  474. 2024-06-25 07:46:21.292045 [DEBUG] sofia.c:6858 Channel sofia/default/27448734188 entering state [ready][200]
  475. 2024-06-25 07:46:21.292045 [NOTICE] sofia.c:7767 Channel [sofia/default/27448734188] has been answered
  476. 2024-06-25 07:46:21.292045 [DEBUG] switch_channel.c:3770 (sofia/default/27448734188) Callstate Change EARLY -> ACTIVE
  477. 2024-06-25 07:46:21.292045 [DEBUG] mod_sofia.c:814 Local SDP sofia/default/27876303987@102.220.232.19:
  478. v=0
  479. o=FreeSWITCH 1719263173 1719263175 IN IP4 196.31.25.87
  480. s=FreeSWITCH
  481. c=IN IP4 196.31.25.87
  482. t=0 0
  483. m=audio 31202 RTP/AVP 8 101
  484. a=rtpmap:8 PCMA/8000
  485. a=rtpmap:101 telephone-event/8000
  486. a=fmtp:101 0-16
  487. a=fmtp:18 annexb=no
  488. a=ptime:20
  489. a=sendrecv
  490.  
  491. 2024-06-25 07:46:21.292045 [NOTICE] switch_ivr_bridge.c:618 Channel [sofia/default/27876303987@102.220.232.19] has been answered
  492. 2024-06-25 07:46:21.292045 [DEBUG] switch_channel.c:3770 (sofia/default/27876303987@102.220.232.19) Callstate Change EARLY -> ACTIVE
  493. 2024-06-25 07:46:21.292045 [DEBUG] sofia.c:6858 Channel sofia/default/27876303987@102.220.232.19 entering state [completed][200]
  494. 2024-06-25 07:46:21.312044 [DEBUG] sofia.c:6858 Channel sofia/default/27876303987@102.220.232.19 entering state [ready][200]
  495. 2024-06-25 07:46:21.352075 [NOTICE] sofia.c:988 Hangup sofia/default/27876303987@102.220.232.19 [CS_EXECUTE] [NORMAL_CLEARING]
  496. 2024-06-25 07:46:21.372107 [DEBUG] switch_ivr_bridge.c:780 BRIDGE THREAD DONE [sofia/default/27876303987@102.220.232.19]
  497. 2024-06-25 07:46:21.372107 [DEBUG] switch_rtp.c:6707 Correct audio ip/port confirmed.
  498. 2024-06-25 07:46:21.372107 [DEBUG] switch_ivr_bridge.c:701 sofia/default/27876303987@102.220.232.19 ending bridge by request from write function
  499. 2024-06-25 07:46:21.372107 [DEBUG] switch_ivr_bridge.c:780 BRIDGE THREAD DONE [sofia/default/27448734188]
  500. 2024-06-25 07:46:21.372107 [NOTICE] switch_ivr_bridge.c:884 Hangup sofia/default/27448734188 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING]
  501. 2024-06-25 07:46:21.372107 [DEBUG] switch_core_state_machine.c:612 (sofia/default/27448734188) State EXCHANGE_MEDIA going to sleep
  502. 2024-06-25 07:46:21.372107 [DEBUG] switch_core_state_machine.c:543 (sofia/default/27448734188) Running State Change CS_HANGUP
  503. 2024-06-25 07:46:21.372107 [DEBUG] switch_core_state_machine.c:809 (sofia/default/27448734188) Callstate Change ACTIVE -> HANGUP
  504. 2024-06-25 07:46:21.372107 [DEBUG] switch_core_state_machine.c:811 (sofia/default/27448734188) State HANGUP
  505. 2024-06-25 07:46:21.372107 [DEBUG] mod_sofia.c:431 sofia/default/27448734188 Overriding SIP cause 480 with 200 from the other leg
  506. 2024-06-25 07:46:21.372107 [DEBUG] mod_sofia.c:437 Channel sofia/default/27448734188 hanging up, cause: NORMAL_CLEARING
  507. 2024-06-25 07:46:21.372107 [DEBUG] switch_ivr_bridge.c:1692 sofia/default/27448734188 skip receive message [UNBRIDGE] (channel is hungup already)
  508. 2024-06-25 07:46:21.372107 [DEBUG] switch_ivr_bridge.c:1695 sofia/default/27876303987@102.220.232.19 skip receive message [UNBRIDGE] (channel is hungup already)
  509. 2024-06-25 07:46:21.372107 [DEBUG] switch_core_session.c:2796 sofia/default/27876303987@102.220.232.19 skip receive message [PHONE_EVENT] (channel is hungup already)
  510. 2024-06-25 07:46:21.372107 [DEBUG] switch_core_session.c:2796 sofia/default/27876303987@102.220.232.19 skip receive message [PHONE_EVENT] (channel is hungup already)
  511. 2024-06-25 07:46:21.372107 [DEBUG] switch_core_state_machine.c:609 (sofia/default/27876303987@102.220.232.19) State EXECUTE going to sleep
  512. 2024-06-25 07:46:21.372107 [DEBUG] switch_core_state_machine.c:543 (sofia/default/27876303987@102.220.232.19) Running State Change CS_HANGUP
  513. 2024-06-25 07:46:21.372107 [DEBUG] switch_core_state_machine.c:809 (sofia/default/27876303987@102.220.232.19) Callstate Change ACTIVE -> HANGUP
  514. 2024-06-25 07:46:21.372107 [DEBUG] mod_sofia.c:490 Sending BYE to sofia/default/27448734188
  515. 2024-06-25 07:46:21.372107 [DEBUG] switch_core_state_machine.c:60 sofia/default/27448734188 Standard HANGUP, cause: NORMAL_CLEARING
  516. 2024-06-25 07:46:21.372107 [DEBUG] switch_core_state_machine.c:811 (sofia/default/27448734188) State HANGUP going to sleep
  517. 2024-06-25 07:46:21.372107 [DEBUG] switch_core_state_machine.c:578 (sofia/default/27448734188) State Change CS_HANGUP -> CS_REPORTING
  518. 2024-06-25 07:46:21.372107 [DEBUG] switch_core_state_machine.c:811 (sofia/default/27876303987@102.220.232.19) State HANGUP
  519. 2024-06-25 07:46:21.372107 [DEBUG] switch_core_state_machine.c:543 (sofia/default/27448734188) Running State Change CS_REPORTING
  520. 2024-06-25 07:46:21.372107 [DEBUG] mod_sofia.c:437 Channel sofia/default/27876303987@102.220.232.19 hanging up, cause: NORMAL_CLEARING
  521. 2024-06-25 07:46:21.372107 [DEBUG] switch_core_state_machine.c:897 (sofia/default/27448734188) State REPORTING
  522. 2024-06-25 07:46:21.372107 [DEBUG] switch_core_state_machine.c:60 sofia/default/27876303987@102.220.232.19 Standard HANGUP, cause: NORMAL_CLEARING
  523. 2024-06-25 07:46:21.372107 [DEBUG] switch_core_state_machine.c:811 (sofia/default/27876303987@102.220.232.19) State HANGUP going to sleep
  524. 2024-06-25 07:46:21.372107 [DEBUG] switch_core_state_machine.c:578 (sofia/default/27876303987@102.220.232.19) State Change CS_HANGUP -> CS_REPORTING
  525. 2024-06-25 07:46:21.372107 [DEBUG] switch_core_state_machine.c:543 (sofia/default/27876303987@102.220.232.19) Running State Change CS_REPORTING
  526. 2024-06-25 07:46:21.372107 [DEBUG] switch_core_state_machine.c:897 (sofia/default/27876303987@102.220.232.19) State REPORTING
  527. 2024-06-25 07:46:21.651974 [DEBUG] switch_core_state_machine.c:174 sofia/default/27448734188 Standard REPORTING, cause: NORMAL_CLEARING
  528. 2024-06-25 07:46:21.651974 [DEBUG] switch_core_state_machine.c:897 (sofia/default/27448734188) State REPORTING going to sleep
  529. 2024-06-25 07:46:21.651974 [DEBUG] switch_core_state_machine.c:569 (sofia/default/27448734188) State Change CS_REPORTING -> CS_DESTROY
  530. 2024-06-25 07:46:21.651974 [DEBUG] switch_core_session.c:1646 Session 5787233 (sofia/default/27448734188) Locked, Waiting on external entities
  531. 2024-06-25 07:46:21.651974 [NOTICE] switch_core_session.c:1664 Session 5787233 (sofia/default/27448734188) Ended
  532. 2024-06-25 07:46:21.651974 [NOTICE] switch_core_session.c:1668 Close Channel sofia/default/27448734188 [CS_DESTROY]
  533. 2024-06-25 07:46:21.651974 [DEBUG] switch_core_state_machine.c:700 (sofia/default/27448734188) Running State Change CS_DESTROY
  534. 2024-06-25 07:46:21.651974 [DEBUG] switch_core_state_machine.c:710 (sofia/default/27448734188) State DESTROY
  535. 2024-06-25 07:46:21.651974 [DEBUG] mod_sofia.c:342 sofia/default/27448734188 SOFIA DESTROY
  536. 2024-06-25 07:46:21.651974 [DEBUG] switch_core_state_machine.c:181 sofia/default/27448734188 Standard DESTROY
  537. 2024-06-25 07:46:21.651974 [DEBUG] switch_core_state_machine.c:710 (sofia/default/27448734188) State DESTROY going to sleep
  538. 2024-06-25 07:46:21.692036 [DEBUG] switch_core_state_machine.c:174 sofia/default/27876303987@102.220.232.19 Standard REPORTING, cause: NORMAL_CLEARING
  539. 2024-06-25 07:46:21.692036 [DEBUG] switch_core_state_machine.c:897 (sofia/default/27876303987@102.220.232.19) State REPORTING going to sleep
  540. 2024-06-25 07:46:21.692036 [DEBUG] switch_core_state_machine.c:569 (sofia/default/27876303987@102.220.232.19) State Change CS_REPORTING -> CS_DESTROY
  541. 2024-06-25 07:46:21.692036 [DEBUG] switch_core_session.c:1646 Session 5787232 (sofia/default/27876303987@102.220.232.19) Locked, Waiting on external entities
  542. 2024-06-25 07:46:21.692036 [NOTICE] switch_core_session.c:1664 Session 5787232 (sofia/default/27876303987@102.220.232.19) Ended
  543. 2024-06-25 07:46:21.692036 [NOTICE] switch_core_session.c:1668 Close Channel sofia/default/27876303987@102.220.232.19 [CS_DESTROY]
  544. 2024-06-25 07:46:21.692036 [DEBUG] switch_core_state_machine.c:700 (sofia/default/27876303987@102.220.232.19) Running State Change CS_DESTROY
  545. 2024-06-25 07:46:21.692036 [DEBUG] switch_core_state_machine.c:710 (sofia/default/27876303987@102.220.232.19) State DESTROY
  546. 2024-06-25 07:46:21.692036 [DEBUG] mod_sofia.c:342 sofia/default/27876303987@102.220.232.19 SOFIA DESTROY
  547. 2024-06-25 07:46:21.692036 [DEBUG] switch_core_state_machine.c:181 sofia/default/27876303987@102.220.232.19 Standard DESTROY
  548. 2024-06-25 07:46:21.692036 [DEBUG] switch_core_state_machine.c:710 (sofia/default/27876303987@102.220.232.19) State DESTROY going to sleep
  549. 2024-06-25 07:46:22.152004 [DEBUG] switch_scheduler.c:144 Deleting task 2738361 switch_ivr_schedule_hangup (a5d94864-7170-4506-84a1-e088245af79a)
  550. 2024-06-25 07:46:22.272047 [WARNING] sofia_reg.c:2889 Can't find user [27113915665@196.31.25.87] from 196.31.25.91
  551. You must define a domain called '196.31.25.87' in your directory and add a user with the id="27113915665" attribute
  552. and you must configure your device to use the proper domain in it's authentication credentials.
  553. 2024-06-25 07:46:22.272047 [WARNING] sofia_reg.c:2889 Can't find user [27317647531@196.31.25.87] from 196.31.25.91
  554. You must define a domain called '196.31.25.87' in your directory and add a user with the id="27317647531" attribute
  555. and you must configure your device to use the proper domain in it's authentication credentials.
  556. 2024-06-25 07:46:23.632042 [DEBUG] sofia.c:6858 Channel sofia/default/27119751588 entering state [completing][200]
  557. 2024-06-25 07:46:23.632042 [DEBUG] sofia.c:6868 Remote SDP:
  558. v=0
  559. o=PortaSIP 4523595345405747229 1 IN IP4 197.97.67.168
  560. s=-
  561. t=0 0
  562. m=audio 20532 RTP/AVP 8 101
  563. c=IN IP4 197.97.67.168
  564. a=rtpmap:8 PCMA/8000
  565. a=rtpmap:101 telephone-event/8000
  566. a=fmtp:101 0-15
  567. a=ptime:20
  568.  
  569. 2024-06-25 07:46:23.632042 [DEBUG] sofia.c:6858 Channel sofia/default/27119751588 entering state [ready][200]
  570. 2024-06-25 07:46:23.632042 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G729:18:8000:20:8000:1]
  571. 2024-06-25 07:46:23.632042 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  572. 2024-06-25 07:46:23.632042 [DEBUG] switch_core_media.c:4410 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
  573. 2024-06-25 07:46:23.632042 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  574. 2024-06-25 07:46:23.632042 [DEBUG] switch_core_media.c:4271 Set telephone-event payload to 101@8000
  575. 2024-06-25 07:46:23.632042 [DEBUG] switch_core_media.c:3090 Set Codec sofia/default/27119751588 PCMA/8000 20 ms 160 samples 64000 bits 1 channels
  576. 2024-06-25 07:46:23.632042 [DEBUG] switch_core_codec.c:111 sofia/default/27119751588 Original read codec set to PCMA:8
  577. 2024-06-25 07:46:23.632042 [DEBUG] switch_core_media.c:4623 Set telephone-event payload to 101@8000
  578. 2024-06-25 07:46:23.632042 [DEBUG] switch_core_media.c:4681 sofia/default/27119751588 Set 2833 dtmf send payload to 101 recv payload to 101
  579. 2024-06-25 07:46:23.632042 [DEBUG] switch_core_media.c:6464 AUDIO RTP [sofia/default/27119751588] 196.31.25.87 port 18906 -> 197.97.67.168 port 20532 codec: 8 ms: 20
  580. 2024-06-25 07:46:23.632042 [DEBUG] switch_rtp.c:3832 Starting timer [soft] 160 bytes per 20ms
  581. 2024-06-25 07:46:23.632042 [DEBUG] switch_core_media.c:6763 sofia/default/27119751588 Set 2833 dtmf send payload to 101
  582. 2024-06-25 07:46:23.632042 [DEBUG] switch_core_media.c:6770 sofia/default/27119751588 Set 2833 dtmf receive payload to 101
  583. 2024-06-25 07:46:23.632042 [DEBUG] switch_core_media.c:6793 sofia/default/27119751588 Set rtp dtmf delay to 40
  584. 2024-06-25 07:46:23.632042 [NOTICE] sofia.c:7826 Channel [sofia/default/27119751588] has been answered
  585. 2024-06-25 07:46:23.632042 [DEBUG] switch_channel.c:3770 (sofia/default/27119751588) Callstate Change RINGING -> ACTIVE
  586. 2024-06-25 07:46:23.652065 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [G729:18:8000:20:8000:1]/[G729:18:8000:20:8000:1]
  587. 2024-06-25 07:46:23.652065 [DEBUG] switch_core_media.c:4410 Audio Codec Compare [G729:18:8000:20:8000:1] ++++ is saved as a match
  588. 2024-06-25 07:46:23.652065 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
  589. 2024-06-25 07:46:23.652065 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
  590. 2024-06-25 07:46:23.652065 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G729:18:8000:20:8000:1]
  591. 2024-06-25 07:46:23.652065 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  592. 2024-06-25 07:46:23.652065 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  593. 2024-06-25 07:46:23.652065 [DEBUG] switch_core_media.c:4410 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
  594. 2024-06-25 07:46:23.652065 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G729:18:8000:20:8000:1]
  595. 2024-06-25 07:46:23.652065 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  596. 2024-06-25 07:46:23.652065 [DEBUG] switch_core_media.c:4410 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
  597. 2024-06-25 07:46:23.652065 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  598. 2024-06-25 07:46:23.652065 [DEBUG] switch_core_media.c:4271 Set telephone-event payload to 101@8000
  599. 2024-06-25 07:46:23.652065 [DEBUG] switch_core_media.c:3090 Set Codec sofia/default/27118921900@gtsbc.goldtelcloud.co.za G729/8000 20 ms 160 samples 8000 bits 1 channels
  600. 2024-06-25 07:46:23.652065 [DEBUG] switch_core_codec.c:111 sofia/default/27118921900@gtsbc.goldtelcloud.co.za Original read codec set to G729:18
  601. 2024-06-25 07:46:23.652065 [DEBUG] switch_core_media.c:4623 Set telephone-event payload to 101@8000
  602. 2024-06-25 07:46:23.652065 [DEBUG] switch_core_media.c:4681 sofia/default/27118921900@gtsbc.goldtelcloud.co.za Set 2833 dtmf send payload to 101 recv payload to 101
  603. 2024-06-25 07:46:23.652065 [DEBUG] switch_core_media.c:6464 AUDIO RTP [sofia/default/27118921900@gtsbc.goldtelcloud.co.za] 196.31.25.87 port 25604 -> 41.4.17.223 port 8012 codec: 18 ms: 20
  604. 2024-06-25 07:46:23.652065 [DEBUG] switch_rtp.c:3832 Starting timer [soft] 160 bytes per 20ms
  605. 2024-06-25 07:46:23.652065 [DEBUG] switch_core_media.c:6763 sofia/default/27118921900@gtsbc.goldtelcloud.co.za Set 2833 dtmf send payload to 101
  606. 2024-06-25 07:46:23.652065 [DEBUG] switch_core_media.c:6770 sofia/default/27118921900@gtsbc.goldtelcloud.co.za Set 2833 dtmf receive payload to 101
  607. 2024-06-25 07:46:23.652065 [DEBUG] switch_core_media.c:6793 sofia/default/27118921900@gtsbc.goldtelcloud.co.za Set rtp dtmf delay to 40
  608. 2024-06-25 07:46:23.652065 [NOTICE] sofia_media.c:92 Pre-Answer sofia/default/27118921900@gtsbc.goldtelcloud.co.za!
  609. 2024-06-25 07:46:23.652065 [DEBUG] switch_channel.c:3471 (sofia/default/27118921900@gtsbc.goldtelcloud.co.za) Callstate Change RINGING -> EARLY
  610. 2024-06-25 07:46:23.652065 [DEBUG] mod_sofia.c:814 Local SDP sofia/default/27118921900@gtsbc.goldtelcloud.co.za:
  611. v=0
  612. o=FreeSWITCH 1719268779 1719268780 IN IP4 196.31.25.87
  613. s=FreeSWITCH
  614. c=IN IP4 196.31.25.87
  615. t=0 0
  616. m=audio 25604 RTP/AVP 18 101
  617. a=rtpmap:18 G729/8000
  618. a=fmtp:18 annexb=no
  619. a=rtpmap:101 telephone-event/8000
  620. a=fmtp:101 0-16
  621. a=fmtp:18 annexb=no
  622. a=ptime:20
  623. a=sendrecv
  624.  
  625. 2024-06-25 07:46:23.652065 [NOTICE] switch_ivr_originate.c:3549 Channel [sofia/default/27118921900@gtsbc.goldtelcloud.co.za] has been answered
  626. 2024-06-25 07:46:23.652065 [DEBUG] switch_channel.c:3770 (sofia/default/27118921900@gtsbc.goldtelcloud.co.za) Callstate Change EARLY -> ACTIVE
  627. 2024-06-25 07:46:23.652065 [DEBUG] sofia.c:6858 Channel sofia/default/27118921900@gtsbc.goldtelcloud.co.za entering state [completed][200]
  628. 2024-06-25 07:46:23.652065 [DEBUG] switch_ivr_originate.c:3607 Originate Resulted in Success: [sofia/default/27119751588]
  629. 2024-06-25 07:46:23.652065 [DEBUG] switch_ivr_bridge.c:1594 (sofia/default/27119751588) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
  630. 2024-06-25 07:46:23.652065 [DEBUG] switch_core_state_machine.c:543 (sofia/default/27119751588) Running State Change CS_EXCHANGE_MEDIA
  631. 2024-06-25 07:46:23.652065 [DEBUG] switch_core_state_machine.c:612 (sofia/default/27119751588) State EXCHANGE_MEDIA
  632. 2024-06-25 07:46:23.652065 [DEBUG] mod_sofia.c:628 SOFIA EXCHANGE_MEDIA
  633. 2024-06-25 07:46:23.692072 [NOTICE] sofia.c:988 Hangup sofia/default/27844641830 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING]
  634. 2024-06-25 07:46:23.692072 [DEBUG] switch_ivr_bridge.c:780 BRIDGE THREAD DONE [sofia/default/27844641830]
  635. 2024-06-25 07:46:23.692072 [DEBUG] switch_core_state_machine.c:612 (sofia/default/27844641830) State EXCHANGE_MEDIA going to sleep
  636. 2024-06-25 07:46:23.692072 [DEBUG] switch_core_state_machine.c:543 (sofia/default/27844641830) Running State Change CS_HANGUP
  637. 2024-06-25 07:46:23.692072 [DEBUG] switch_core_state_machine.c:809 (sofia/default/27844641830) Callstate Change ACTIVE -> HANGUP
  638. 2024-06-25 07:46:23.692072 [DEBUG] switch_core_state_machine.c:811 (sofia/default/27844641830) State HANGUP
  639. 2024-06-25 07:46:23.692072 [DEBUG] mod_sofia.c:437 Channel sofia/default/27844641830 hanging up, cause: NORMAL_CLEARING
  640. 2024-06-25 07:46:23.692072 [DEBUG] switch_core_state_machine.c:60 sofia/default/27844641830 Standard HANGUP, cause: NORMAL_CLEARING
  641. 2024-06-25 07:46:23.692072 [DEBUG] switch_core_state_machine.c:811 (sofia/default/27844641830) State HANGUP going to sleep
  642. 2024-06-25 07:46:23.692072 [DEBUG] switch_core_state_machine.c:578 (sofia/default/27844641830) State Change CS_HANGUP -> CS_REPORTING
  643. 2024-06-25 07:46:23.692072 [DEBUG] switch_core_state_machine.c:543 (sofia/default/27844641830) Running State Change CS_REPORTING
  644. 2024-06-25 07:46:23.692072 [DEBUG] switch_core_state_machine.c:897 (sofia/default/27844641830) State REPORTING
  645. 2024-06-25 07:46:23.692072 [DEBUG] switch_rtp.c:6707 Correct audio ip/port confirmed.
  646. 2024-06-25 07:46:23.692072 [DEBUG] sofia.c:6858 Channel sofia/default/27118921900@gtsbc.goldtelcloud.co.za entering state [ready][200]
  647. 2024-06-25 07:46:23.711967 [DEBUG] switch_ivr_bridge.c:701 sofia/default/27844641830 ending bridge by request from write function
  648. 2024-06-25 07:46:23.711967 [DEBUG] switch_ivr_bridge.c:780 BRIDGE THREAD DONE [sofia/default/27113395539@nopa:7011]
  649. 2024-06-25 07:46:23.711967 [DEBUG] switch_ivr_bridge.c:1692 sofia/default/27844641830 skip receive message [UNBRIDGE] (channel is hungup already)
  650. 2024-06-25 07:46:23.711967 [NOTICE] switch_ivr_bridge.c:1744 Hangup sofia/default/27113395539@nopa:7011 [CS_EXECUTE] [NORMAL_CLEARING]
  651. 2024-06-25 07:46:23.711967 [DEBUG] switch_core_session.c:2796 sofia/default/27113395539@nopa:7011 skip receive message [PHONE_EVENT] (channel is hungup already)
  652. 2024-06-25 07:46:23.711967 [DEBUG] switch_core_session.c:2796 sofia/default/27113395539@nopa:7011 skip receive message [PHONE_EVENT] (channel is hungup already)
  653. 2024-06-25 07:46:23.711967 [DEBUG] switch_core_state_machine.c:609 (sofia/default/27113395539@nopa:7011) State EXECUTE going to sleep
  654. 2024-06-25 07:46:23.711967 [DEBUG] switch_core_state_machine.c:543 (sofia/default/27113395539@nopa:7011) Running State Change CS_HANGUP
  655. 2024-06-25 07:46:23.711967 [DEBUG] switch_core_state_machine.c:809 (sofia/default/27113395539@nopa:7011) Callstate Change ACTIVE -> HANGUP
  656. 2024-06-25 07:46:23.711967 [DEBUG] switch_core_state_machine.c:811 (sofia/default/27113395539@nopa:7011) State HANGUP
  657. 2024-06-25 07:46:23.711967 [DEBUG] mod_sofia.c:431 sofia/default/27113395539@nopa:7011 Overriding SIP cause 480 with 200 from the other leg
  658. 2024-06-25 07:46:23.711967 [DEBUG] mod_sofia.c:437 Channel sofia/default/27113395539@nopa:7011 hanging up, cause: NORMAL_CLEARING
  659. 2024-06-25 07:46:23.711967 [DEBUG] mod_sofia.c:490 Sending BYE to sofia/default/27113395539@nopa:7011
  660. 2024-06-25 07:46:23.711967 [DEBUG] switch_core_state_machine.c:60 sofia/default/27113395539@nopa:7011 Standard HANGUP, cause: NORMAL_CLEARING
  661. 2024-06-25 07:46:23.711967 [DEBUG] switch_core_state_machine.c:811 (sofia/default/27113395539@nopa:7011) State HANGUP going to sleep
  662. 2024-06-25 07:46:23.711967 [DEBUG] switch_core_state_machine.c:578 (sofia/default/27113395539@nopa:7011) State Change CS_HANGUP -> CS_REPORTING
  663. 2024-06-25 07:46:23.711967 [DEBUG] switch_core_state_machine.c:543 (sofia/default/27113395539@nopa:7011) Running State Change CS_REPORTING
  664. 2024-06-25 07:46:23.711967 [DEBUG] switch_core_state_machine.c:897 (sofia/default/27113395539@nopa:7011) State REPORTING
  665. 2024-06-25 07:46:23.971974 [DEBUG] switch_core_state_machine.c:174 sofia/default/27844641830 Standard REPORTING, cause: NORMAL_CLEARING
  666. 2024-06-25 07:46:23.971974 [DEBUG] switch_core_state_machine.c:897 (sofia/default/27844641830) State REPORTING going to sleep
  667. 2024-06-25 07:46:23.971974 [DEBUG] switch_core_state_machine.c:569 (sofia/default/27844641830) State Change CS_REPORTING -> CS_DESTROY
  668. 2024-06-25 07:46:23.971974 [DEBUG] switch_core_session.c:1646 Session 5787179 (sofia/default/27844641830) Locked, Waiting on external entities
  669. 2024-06-25 07:46:23.971974 [NOTICE] switch_core_session.c:1664 Session 5787179 (sofia/default/27844641830) Ended
  670. 2024-06-25 07:46:23.971974 [NOTICE] switch_core_session.c:1668 Close Channel sofia/default/27844641830 [CS_DESTROY]
  671. 2024-06-25 07:46:23.971974 [DEBUG] switch_core_state_machine.c:700 (sofia/default/27844641830) Running State Change CS_DESTROY
  672. 2024-06-25 07:46:23.971974 [DEBUG] switch_core_state_machine.c:710 (sofia/default/27844641830) State DESTROY
  673. 2024-06-25 07:46:23.971974 [DEBUG] mod_sofia.c:342 sofia/default/27844641830 SOFIA DESTROY
  674. 2024-06-25 07:46:23.971974 [DEBUG] switch_core_state_machine.c:181 sofia/default/27844641830 Standard DESTROY
  675. 2024-06-25 07:46:23.971974 [DEBUG] switch_core_state_machine.c:710 (sofia/default/27844641830) State DESTROY going to sleep
  676. 2024-06-25 07:46:23.991975 [INFO] switch_rtp.c:6669 Auto Changing audio port from 41.4.17.223:8012 to 41.4.17.223:36869
  677. 2024-06-25 07:46:24.032051 [DEBUG] switch_core_state_machine.c:174 sofia/default/27113395539@nopa:7011 Standard REPORTING, cause: NORMAL_CLEARING
  678. 2024-06-25 07:46:24.032051 [DEBUG] switch_core_state_machine.c:897 (sofia/default/27113395539@nopa:7011) State REPORTING going to sleep
  679. 2024-06-25 07:46:24.032051 [DEBUG] switch_core_state_machine.c:569 (sofia/default/27113395539@nopa:7011) State Change CS_REPORTING -> CS_DESTROY
  680. 2024-06-25 07:46:24.032051 [DEBUG] switch_core_session.c:1646 Session 5787178 (sofia/default/27113395539@nopa:7011) Locked, Waiting on external entities
  681. 2024-06-25 07:46:24.032051 [NOTICE] switch_core_session.c:1664 Session 5787178 (sofia/default/27113395539@nopa:7011) Ended
  682. 2024-06-25 07:46:24.032051 [NOTICE] switch_core_session.c:1668 Close Channel sofia/default/27113395539@nopa:7011 [CS_DESTROY]
  683. 2024-06-25 07:46:24.032051 [DEBUG] switch_core_state_machine.c:700 (sofia/default/27113395539@nopa:7011) Running State Change CS_DESTROY
  684. 2024-06-25 07:46:24.032051 [DEBUG] switch_core_state_machine.c:710 (sofia/default/27113395539@nopa:7011) State DESTROY
  685. 2024-06-25 07:46:24.032051 [DEBUG] mod_sofia.c:342 sofia/default/27113395539@nopa:7011 SOFIA DESTROY
  686. 2024-06-25 07:46:24.032051 [DEBUG] switch_core_state_machine.c:181 sofia/default/27113395539@nopa:7011 Standard DESTROY
  687. 2024-06-25 07:46:24.032051 [DEBUG] switch_core_state_machine.c:710 (sofia/default/27113395539@nopa:7011) State DESTROY going to sleep
  688. 2024-06-25 07:46:24.152048 [DEBUG] switch_scheduler.c:144 Deleting task 2738334 switch_ivr_schedule_hangup (d6d281d1-c2d8-46d1-a5b0-14f8efabbf92)
  689. 2024-06-25 07:46:27.392051 [NOTICE] switch_channel.c:1104 New Channel sofia/default/27446903578@197.97.67.136:5060 [be99a2a3-8724-47a8-b870-204e79e1426c]
  690. 2024-06-25 07:46:27.392051 [DEBUG] switch_core_state_machine.c:543 (sofia/default/27446903578@197.97.67.136:5060) Running State Change CS_NEW
  691. 2024-06-25 07:46:27.392051 [DEBUG] sofia.c:9376 sofia/default/27446903578@197.97.67.136:5060 receiving invite from 196.31.25.91:5060 version: 1.6.8  64bit
  692. 2024-06-25 07:46:27.392051 [DEBUG] sofia.c:9498 1 acls to check for proxy
  693. 2024-06-25 07:46:27.392051 [DEBUG] sofia.c:9503 checking 196.31.25.91 against acl proxy_acl
  694. 2024-06-25 07:46:27.392051 [INFO] sofia.c:9505 196.31.25.91 is a proxy according to the proxy_acl acl
  695. 2024-06-25 07:46:27.392051 [DEBUG] sofia.c:9515 network ip is a proxy
  696. 2024-06-25 07:46:27.392051 [DEBUG] sofia.c:9519 found auth ip [X-AUTH-IP] header of [197.97.67.136]
  697. 2024-06-25 07:46:27.392051 [DEBUG] sofia.c:9551 IP 197.97.67.136 Approved by acl "default[]". Access Granted.
  698. 2024-06-25 07:46:27.392051 [DEBUG] sofia.c:6858 Channel sofia/default/27446903578@197.97.67.136:5060 entering state [received][100]
  699. 2024-06-25 07:46:27.392051 [DEBUG] sofia.c:6868 Remote SDP:
  700. v=0
  701. o=PortaSIP 2572680169871076604 1 IN IP4 197.97.67.136
  702. s=-
  703. t=0 0
  704. m=audio 20740 RTP/AVP 18 8 0 98
  705. c=IN IP4 197.97.67.136
  706. a=rtpmap:18 G729/8000
  707. a=fmtp:18 annexb=yes
  708. a=rtpmap:8 PCMA/8000
  709. a=rtpmap:0 PCMU/8000
  710. a=rtpmap:98 telephone-event/8000
  711. a=fmtp:98 0-15
  712. a=maxptime:40
  713. a=ptime:20
  714.  
  715. 2024-06-25 07:46:27.392051 [DEBUG] sofia.c:7227 (sofia/default/27446903578@197.97.67.136:5060) State Change CS_NEW -> CS_INIT
  716. 2024-06-25 07:46:27.392051 [DEBUG] switch_core_state_machine.c:562 (sofia/default/27446903578@197.97.67.136:5060) State NEW
  717. 2024-06-25 07:46:27.392051 [DEBUG] switch_core_state_machine.c:543 (sofia/default/27446903578@197.97.67.136:5060) Running State Change CS_INIT
  718. 2024-06-25 07:46:27.392051 [DEBUG] switch_core_state_machine.c:586 (sofia/default/27446903578@197.97.67.136:5060) State INIT
  719. 2024-06-25 07:46:27.392051 [DEBUG] mod_sofia.c:89 sofia/default/27446903578@197.97.67.136:5060 SOFIA INIT
  720. 2024-06-25 07:46:27.392051 [DEBUG] switch_core_state_machine.c:40 sofia/default/27446903578@197.97.67.136:5060 Standard INIT
  721. 2024-06-25 07:46:27.392051 [DEBUG] switch_core_state_machine.c:48 (sofia/default/27446903578@197.97.67.136:5060) State Change CS_INIT -> CS_ROUTING
  722. 2024-06-25 07:46:27.392051 [DEBUG] switch_core_state_machine.c:586 (sofia/default/27446903578@197.97.67.136:5060) State INIT going to sleep
  723. 2024-06-25 07:46:27.392051 [DEBUG] switch_core_state_machine.c:543 (sofia/default/27446903578@197.97.67.136:5060) Running State Change CS_ROUTING
  724. 2024-06-25 07:46:27.392051 [DEBUG] switch_channel.c:2249 (sofia/default/27446903578@197.97.67.136:5060) Callstate Change DOWN -> RINGING
  725. 2024-06-25 07:46:27.392051 [DEBUG] switch_core_state_machine.c:602 (sofia/default/27446903578@197.97.67.136:5060) State ROUTING
  726. 2024-06-25 07:46:27.392051 [DEBUG] mod_sofia.c:142 sofia/default/27446903578@197.97.67.136:5060 SOFIA ROUTING
  727. 2024-06-25 07:46:27.392051 [DEBUG] switch_core_state_machine.c:236 sofia/default/27446903578@197.97.67.136:5060 Standard ROUTING
  728. 2024-06-25 07:46:27.392051 [INFO] mod_dialplan_xml.c:637 Processing 27446903578 <27446903578>->27446913718 in context default
  729. Dialplan: sofia/default/27446903578@197.97.67.136:5060 parsing [default->] continue=false
  730. Dialplan: sofia/default/27446903578@197.97.67.136:5060 Regex (PASS) [] destination_number(27446913718) =~ // break=on-false
  731. Dialplan: sofia/default/27446903578@197.97.67.136:5060 Action set(callstart=2024-06-25 05:46:27)
  732. Dialplan: sofia/default/27446903578@197.97.67.136:5060 Action set(call_processed=internal)
  733. Dialplan: sofia/default/27446903578@197.97.67.136:5060 Action set(originated_destination_number=27446913718)
  734. Dialplan: sofia/default/27446903578@197.97.67.136:5060 Action set(hangup_after_bridge=true)
  735. Dialplan: sofia/default/27446903578@197.97.67.136:5060 Action set(fax_enable_t38=true)
  736. Dialplan: sofia/default/27446903578@197.97.67.136:5060 Action set(fax_enable_t38_request=true)
  737. Dialplan: sofia/default/27446903578@197.97.67.136:5060 Action export(t38_passthru=true)
  738. Dialplan: sofia/default/27446903578@197.97.67.136:5060 Action set(accountid=2030)
  739. Dialplan: sofia/default/27446903578@197.97.67.136:5060 Action set(account_type=0)
  740. Dialplan: sofia/default/27446903578@197.97.67.136:5060 Action set(resellerid=1736)
  741. Dialplan: sofia/default/27446903578@197.97.67.136:5060 Action set(accountcode=2826018430)
  742. Dialplan: sofia/default/27446903578@197.97.67.136:5060 Action set(call_direction=inbound)
  743. Dialplan: sofia/default/27446903578@197.97.67.136:5060 Action set(calltype=DID)
  744. Dialplan: sofia/default/27446903578@197.97.67.136:5060 Action sched_hangup(+6000 allotted_timeout)
  745. Dialplan: sofia/default/27446903578@197.97.67.136:5060 Action set(effective_destination_number=27446913718)
  746. Dialplan: sofia/default/27446903578@197.97.67.136:5060 Action set(ringback=%(2000, 4000, 440.0, 480.0))
  747. Dialplan: sofia/default/27446903578@197.97.67.136:5060 Action set(origination_rates=ID:7613|CODE:^.27446913718.*|DESTINATION:Goldtel ported|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:0.00000|INC:0|RATEGROUP:501|MARKUP:0|ACCID:2030||ID:2030|CODE:^.27446913718.*|DESTINATION:Goldtel ported|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:0.00000|INC:1|RATEGROUP:396|MARKUP:0|ACCID:1736)
  748. Dialplan: sofia/default/27446903578@197.97.67.136:5060 Action set(DID_Caller=)
  749. Dialplan: sofia/default/27446903578@197.97.67.136:5060 Action set(hangup_after_bridge=true)
  750. Dialplan: sofia/default/27446903578@197.97.67.136:5060 Action set(continue_on_fail=true)
  751. Dialplan: sofia/default/27446903578@197.97.67.136:5060 Action export(absolute_codec_string=^^:G729:PCMA:PCMU)
  752. Dialplan: sofia/default/27446903578@197.97.67.136:5060 Action bridge({sip_invite_to_uri=<sip:27446913718@102.220.234.249:8356,sip_invite_req_uri=sip:27446913718@102.220.234.249:8356}sofia/default/sip:27446913718@102.220.234.249:8356;transport=UDP;fs_path=sip%3A196.31.25.91%3Blr%3Breceived%3Dsip%3A102.220.234.249%3A8356)
  753. Dialplan: sofia/default/27446903578@197.97.67.136:5060 Action set(did_number=27446913718)
  754. Dialplan: sofia/default/27446903578@197.97.67.136:5060 Action set(dialed_user=27446913718)
  755. Dialplan: sofia/default/27446903578@197.97.67.136:5060 Action set(is_local_extension=1)
  756. Dialplan: sofia/default/27446903578@197.97.67.136:5060 Action set(ALWAYS_vm_flag=1)
  757. Dialplan: sofia/default/27446903578@197.97.67.136:5060 Action set(USER_BUSY_vm_flag=1)
  758. Dialplan: sofia/default/27446903578@197.97.67.136:5060 Action set(USER_NOT_REGISTERED_vm_flag=1)
  759. Dialplan: sofia/default/27446903578@197.97.67.136:5060 Action set(NO_ANSWER_vm_flag=1)
  760. Dialplan: sofia/default/27446903578@197.97.67.136:5060 Action lua(call_forwarding.lua)
  761. 2024-06-25 07:46:27.532106 [DEBUG] switch_core_state_machine.c:286 (sofia/default/27446903578@197.97.67.136:5060) State Change CS_ROUTING -> CS_EXECUTE
  762. 2024-06-25 07:46:27.532106 [DEBUG] switch_core_state_machine.c:602 (sofia/default/27446903578@197.97.67.136:5060) State ROUTING going to sleep
  763. 2024-06-25 07:46:27.532106 [DEBUG] switch_core_state_machine.c:543 (sofia/default/27446903578@197.97.67.136:5060) Running State Change CS_EXECUTE
  764. 2024-06-25 07:46:27.532106 [DEBUG] switch_core_state_machine.c:609 (sofia/default/27446903578@197.97.67.136:5060) State EXECUTE
  765. 2024-06-25 07:46:27.532106 [DEBUG] mod_sofia.c:197 sofia/default/27446903578@197.97.67.136:5060 SOFIA EXECUTE
  766. 2024-06-25 07:46:27.532106 [DEBUG] switch_core_state_machine.c:328 sofia/default/27446903578@197.97.67.136:5060 Standard EXECUTE
  767. EXECUTE sofia/default/27446903578@197.97.67.136:5060 set(callstart=2024-06-25 05:46:27)
  768. 2024-06-25 07:46:27.532106 [DEBUG] mod_dptools.c:1519 SET sofia/default/27446903578@197.97.67.136:5060 [callstart]=[2024-06-25 05:46:27]
  769. EXECUTE sofia/default/27446903578@197.97.67.136:5060 set(call_processed=internal)
  770. 2024-06-25 07:46:27.532106 [DEBUG] mod_dptools.c:1519 SET sofia/default/27446903578@197.97.67.136:5060 [call_processed]=[internal]
  771. EXECUTE sofia/default/27446903578@197.97.67.136:5060 set(originated_destination_number=27446913718)
  772. 2024-06-25 07:46:27.532106 [DEBUG] mod_dptools.c:1519 SET sofia/default/27446903578@197.97.67.136:5060 [originated_destination_number]=[27446913718]
  773. EXECUTE sofia/default/27446903578@197.97.67.136:5060 set(hangup_after_bridge=true)
  774. 2024-06-25 07:46:27.532106 [DEBUG] mod_dptools.c:1519 SET sofia/default/27446903578@197.97.67.136:5060 [hangup_after_bridge]=[true]
  775. EXECUTE sofia/default/27446903578@197.97.67.136:5060 set(fax_enable_t38=true)
  776. 2024-06-25 07:46:27.532106 [DEBUG] mod_dptools.c:1519 SET sofia/default/27446903578@197.97.67.136:5060 [fax_enable_t38]=[true]
  777. EXECUTE sofia/default/27446903578@197.97.67.136:5060 set(fax_enable_t38_request=true)
  778. 2024-06-25 07:46:27.532106 [DEBUG] mod_dptools.c:1519 SET sofia/default/27446903578@197.97.67.136:5060 [fax_enable_t38_request]=[true]
  779. EXECUTE sofia/default/27446903578@197.97.67.136:5060 export(t38_passthru=true)
  780. 2024-06-25 07:46:27.532106 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [t38_passthru]=[true]
  781. EXECUTE sofia/default/27446903578@197.97.67.136:5060 set(accountid=2030)
  782. 2024-06-25 07:46:27.532106 [DEBUG] mod_dptools.c:1519 SET sofia/default/27446903578@197.97.67.136:5060 [accountid]=[2030]
  783. EXECUTE sofia/default/27446903578@197.97.67.136:5060 set(account_type=0)
  784. 2024-06-25 07:46:27.532106 [DEBUG] mod_dptools.c:1519 SET sofia/default/27446903578@197.97.67.136:5060 [account_type]=[0]
  785. EXECUTE sofia/default/27446903578@197.97.67.136:5060 set(resellerid=1736)
  786. 2024-06-25 07:46:27.532106 [DEBUG] mod_dptools.c:1519 SET sofia/default/27446903578@197.97.67.136:5060 [resellerid]=[1736]
  787. EXECUTE sofia/default/27446903578@197.97.67.136:5060 set(accountcode=2826018430)
  788. 2024-06-25 07:46:27.532106 [DEBUG] mod_dptools.c:1519 SET sofia/default/27446903578@197.97.67.136:5060 [accountcode]=[2826018430]
  789. EXECUTE sofia/default/27446903578@197.97.67.136:5060 set(call_direction=inbound)
  790. 2024-06-25 07:46:27.532106 [DEBUG] mod_dptools.c:1519 SET sofia/default/27446903578@197.97.67.136:5060 [call_direction]=[inbound]
  791. EXECUTE sofia/default/27446903578@197.97.67.136:5060 set(calltype=DID)
  792. 2024-06-25 07:46:27.532106 [DEBUG] mod_dptools.c:1519 SET sofia/default/27446903578@197.97.67.136:5060 [calltype]=[DID]
  793. EXECUTE sofia/default/27446903578@197.97.67.136:5060 sched_hangup(+6000 allotted_timeout)
  794. 2024-06-25 07:46:27.532106 [DEBUG] switch_scheduler.c:249 Added task 2738363 switch_ivr_schedule_hangup (be99a2a3-8724-47a8-b870-204e79e1426c) to run at 1719300387
  795. EXECUTE sofia/default/27446903578@197.97.67.136:5060 set(effective_destination_number=27446913718)
  796. 2024-06-25 07:46:27.532106 [DEBUG] mod_dptools.c:1519 SET sofia/default/27446903578@197.97.67.136:5060 [effective_destination_number]=[27446913718]
  797. EXECUTE sofia/default/27446903578@197.97.67.136:5060 set(ringback=%(2000, 4000, 440.0, 480.0))
  798. 2024-06-25 07:46:27.532106 [DEBUG] mod_dptools.c:1519 SET sofia/default/27446903578@197.97.67.136:5060 [ringback]=[%(2000, 4000, 440.0, 480.0)]
  799. EXECUTE sofia/default/27446903578@197.97.67.136:5060 set(origination_rates=ID:7613|CODE:^.27446913718.*|DESTINATION:Goldtel ported|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:0.00000|INC:0|RATEGROUP:501|MARKUP:0|ACCID:2030||ID:2030|CODE:^.27446913718.*|DESTINATION:Goldtel ported|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:0.00000|INC:1|RATEGROUP:396|MARKUP:0|ACCID:1736)
  800. 2024-06-25 07:46:27.532106 [DEBUG] mod_dptools.c:1519 SET sofia/default/27446903578@197.97.67.136:5060 [origination_rates]=[ID:7613|CODE:^.27446913718.*|DESTINATION:Goldtel ported|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:0.00000|INC:0|RATEGROUP:501|MARKUP:0|ACCID:2030||ID:2030|CODE:^.27446913718.*|DESTINATION:Goldtel ported|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:0.00000|INC:1|RATEGROUP:396|MARKUP:0|ACCID:1736]
  801. EXECUTE sofia/default/27446903578@197.97.67.136:5060 set(DID_Caller=)
  802. 2024-06-25 07:46:27.532106 [DEBUG] mod_dptools.c:1519 SET sofia/default/27446903578@197.97.67.136:5060 [DID_Caller]=[UNDEF]
  803. EXECUTE sofia/default/27446903578@197.97.67.136:5060 set(hangup_after_bridge=true)
  804. 2024-06-25 07:46:27.532106 [DEBUG] mod_dptools.c:1519 SET sofia/default/27446903578@197.97.67.136:5060 [hangup_after_bridge]=[true]
  805. EXECUTE sofia/default/27446903578@197.97.67.136:5060 set(continue_on_fail=true)
  806. 2024-06-25 07:46:27.532106 [DEBUG] mod_dptools.c:1519 SET sofia/default/27446903578@197.97.67.136:5060 [continue_on_fail]=[true]
  807. EXECUTE sofia/default/27446903578@197.97.67.136:5060 export(absolute_codec_string=^^:G729:PCMA:PCMU)
  808. 2024-06-25 07:46:27.532106 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [absolute_codec_string]=[^^:G729:PCMA:PCMU]
  809. EXECUTE sofia/default/27446903578@197.97.67.136:5060 bridge({sip_invite_to_uri=<sip:27446913718@102.220.234.249:8356,sip_invite_req_uri=sip:27446913718@102.220.234.249:8356}sofia/default/sip:27446913718@102.220.234.249:8356;transport=UDP;fs_path=sip%3A196.31.25.91%3Blr%3Breceived%3Dsip%3A102.220.234.249%3A8356)
  810. 2024-06-25 07:46:27.532106 [DEBUG] switch_channel.c:1250 sofia/default/27446903578@197.97.67.136:5060 EXPORTING[export_vars] [t38_passthru]=[true] to event
  811. 2024-06-25 07:46:27.532106 [DEBUG] switch_channel.c:1250 sofia/default/27446903578@197.97.67.136:5060 EXPORTING[export_vars] [absolute_codec_string]=[^^:G729:PCMA:PCMU] to event
  812. 2024-06-25 07:46:27.532106 [DEBUG] switch_ivr_originate.c:2127 Parsing global variables
  813. 2024-06-25 07:46:27.532106 [NOTICE] switch_channel.c:1104 New Channel sofia/default/27446913718@102.220.234.249:8356 [c15c53cf-f78a-41c5-9603-1fc2a79b2c76]
  814. 2024-06-25 07:46:27.532106 [DEBUG] mod_sofia.c:4813 (sofia/default/27446913718@102.220.234.249:8356) State Change CS_NEW -> CS_INIT
  815. 2024-06-25 07:46:27.532106 [DEBUG] switch_core_state_machine.c:543 (sofia/default/27446913718@102.220.234.249:8356) Running State Change CS_INIT
  816. 2024-06-25 07:46:27.532106 [DEBUG] switch_core_state_machine.c:586 (sofia/default/27446913718@102.220.234.249:8356) State INIT
  817. 2024-06-25 07:46:27.532106 [DEBUG] mod_sofia.c:89 sofia/default/27446913718@102.220.234.249:8356 SOFIA INIT
  818. 2024-06-25 07:46:27.532106 [DEBUG] sofia_glue.c:1228 sip:196.31.25.91;lr;received=sip:102.220.234.249:8356 Setting proxy route to sofia/default/27446913718@102.220.234.249:8356
  819. 2024-06-25 07:46:27.532106 [DEBUG] sofia_glue.c:1257 sofia/default/27446913718@102.220.234.249:8356 sending invite version: 1.6.8  64bit
  820. Local SDP:
  821. v=0
  822. o=FreeSWITCH 1719267855 1719267856 IN IP4 196.31.25.87
  823. s=FreeSWITCH
  824. c=IN IP4 196.31.25.87
  825. t=0 0
  826. m=audio 26532 RTP/AVP 18 8 0 101
  827. a=rtpmap:18 G729/8000
  828. a=fmtp:18 annexb=no
  829. a=rtpmap:8 PCMA/8000
  830. a=rtpmap:0 PCMU/8000
  831. a=rtpmap:101 telephone-event/8000
  832. a=fmtp:101 0-16
  833. a=ptime:20
  834. a=sendrecv
  835.  
  836. 2024-06-25 07:46:27.532106 [DEBUG] switch_core_state_machine.c:40 sofia/default/27446913718@102.220.234.249:8356 Standard INIT
  837. 2024-06-25 07:46:27.532106 [DEBUG] switch_core_state_machine.c:48 (sofia/default/27446913718@102.220.234.249:8356) State Change CS_INIT -> CS_ROUTING
  838. 2024-06-25 07:46:27.532106 [DEBUG] switch_core_state_machine.c:586 (sofia/default/27446913718@102.220.234.249:8356) State INIT going to sleep
  839. 2024-06-25 07:46:27.532106 [DEBUG] switch_core_state_machine.c:543 (sofia/default/27446913718@102.220.234.249:8356) Running State Change CS_ROUTING
  840. 2024-06-25 07:46:27.532106 [DEBUG] sofia.c:6858 Channel sofia/default/27446913718@102.220.234.249:8356 entering state [calling][0]
  841. 2024-06-25 07:46:27.532106 [DEBUG] switch_core_state_machine.c:602 (sofia/default/27446913718@102.220.234.249:8356) State ROUTING
  842. 2024-06-25 07:46:27.532106 [DEBUG] mod_sofia.c:142 sofia/default/27446913718@102.220.234.249:8356 SOFIA ROUTING
  843. 2024-06-25 07:46:27.532106 [DEBUG] switch_ivr_originate.c:67 (sofia/default/27446913718@102.220.234.249:8356) State Change CS_ROUTING -> CS_CONSUME_MEDIA
  844. 2024-06-25 07:46:27.532106 [DEBUG] switch_core_state_machine.c:602 (sofia/default/27446913718@102.220.234.249:8356) State ROUTING going to sleep
  845. 2024-06-25 07:46:27.532106 [DEBUG] switch_core_state_machine.c:543 (sofia/default/27446913718@102.220.234.249:8356) Running State Change CS_CONSUME_MEDIA
  846. 2024-06-25 07:46:27.532106 [DEBUG] switch_core_state_machine.c:621 (sofia/default/27446913718@102.220.234.249:8356) State CONSUME_MEDIA
  847. 2024-06-25 07:46:27.532106 [DEBUG] switch_core_state_machine.c:621 (sofia/default/27446913718@102.220.234.249:8356) State CONSUME_MEDIA going to sleep
  848. 2024-06-25 07:46:28.072072 [DEBUG] sofia.c:6858 Channel sofia/default/27446913718@102.220.234.249:8356 entering state [proceeding][180]
  849. 2024-06-25 07:46:28.072072 [NOTICE] sofia.c:6960 Ring-Ready sofia/default/27446913718@102.220.234.249:8356!
  850. 2024-06-25 07:46:28.072072 [DEBUG] switch_channel.c:3343 (sofia/default/27446913718@102.220.234.249:8356) Callstate Change DOWN -> RINGING
  851. 2024-06-25 07:46:28.072072 [INFO] switch_ivr_originate.c:1215 Sending early media
  852. 2024-06-25 07:46:28.072072 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [G729:18:8000:20:8000:1]/[G729:18:8000:20:8000:1]
  853. 2024-06-25 07:46:28.072072 [DEBUG] switch_core_media.c:4410 Audio Codec Compare [G729:18:8000:20:8000:1] ++++ is saved as a match
  854. 2024-06-25 07:46:28.072072 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
  855. 2024-06-25 07:46:28.072072 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
  856. 2024-06-25 07:46:28.072072 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G729:18:8000:20:8000:1]
  857. 2024-06-25 07:46:28.072072 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  858. 2024-06-25 07:46:28.072072 [DEBUG] switch_core_media.c:4410 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
  859. 2024-06-25 07:46:28.072072 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  860. 2024-06-25 07:46:28.072072 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G729:18:8000:20:8000:1]
  861. 2024-06-25 07:46:28.072072 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  862. 2024-06-25 07:46:28.072072 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  863. 2024-06-25 07:46:28.072072 [DEBUG] switch_core_media.c:4410 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
  864. 2024-06-25 07:46:28.072072 [DEBUG] switch_core_media.c:4271 Set telephone-event payload to 98@8000
  865. 2024-06-25 07:46:28.072072 [DEBUG] switch_core_media.c:3090 Set Codec sofia/default/27446903578@197.97.67.136:5060 G729/8000 20 ms 160 samples 8000 bits 1 channels
  866. 2024-06-25 07:46:28.072072 [DEBUG] switch_core_codec.c:111 sofia/default/27446903578@197.97.67.136:5060 Original read codec set to G729:18
  867. 2024-06-25 07:46:28.072072 [DEBUG] switch_core_media.c:4623 Set telephone-event payload to 98@8000
  868. 2024-06-25 07:46:28.072072 [DEBUG] switch_core_media.c:4681 sofia/default/27446903578@197.97.67.136:5060 Set 2833 dtmf send payload to 101 recv payload to 101
  869. 2024-06-25 07:46:28.072072 [DEBUG] switch_core_media.c:6464 AUDIO RTP [sofia/default/27446903578@197.97.67.136:5060] 196.31.25.87 port 17554 -> 197.97.67.136 port 20740 codec: 18 ms: 20
  870. 2024-06-25 07:46:28.072072 [DEBUG] switch_rtp.c:3832 Starting timer [soft] 160 bytes per 20ms
  871. 2024-06-25 07:46:28.092071 [DEBUG] switch_core_media.c:6763 sofia/default/27446903578@197.97.67.136:5060 Set 2833 dtmf send payload to 101
  872. 2024-06-25 07:46:28.092071 [DEBUG] switch_core_media.c:6770 sofia/default/27446903578@197.97.67.136:5060 Set 2833 dtmf receive payload to 101
  873. 2024-06-25 07:46:28.092071 [DEBUG] switch_core_media.c:6793 sofia/default/27446903578@197.97.67.136:5060 Set rtp dtmf delay to 40
  874. 2024-06-25 07:46:28.092071 [NOTICE] sofia_media.c:92 Pre-Answer sofia/default/27446903578@197.97.67.136:5060!
  875. 2024-06-25 07:46:28.092071 [DEBUG] switch_channel.c:3471 (sofia/default/27446903578@197.97.67.136:5060) Callstate Change RINGING -> EARLY
  876. 2024-06-25 07:46:28.092071 [DEBUG] mod_sofia.c:2367 Ring SDP:
  877. v=0
  878. o=FreeSWITCH 1719276834 1719276835 IN IP4 196.31.25.87
  879.