From Ample Finch, 5 Years ago, written in FreeSWITCH.
- view diff
Embed
  1. span style="color: cornflowerblue; font-weight: bold;"> 2019-01-30 14:58:11.685449 [NOTICE] switch_channel.c:1104 New Channel sofia/default/0117896884@172.31.32.71 [f584c9b5-b274-4348-b31d-d2232a1f6272]
  2. 2019-01-30 14:58:11.685449 [DEBUG] switch_core_state_machine.c:584 (sofia/default/0117896884@172.31.32.71) Running State Change CS_NEW (Cur 1 Tot 142006)
  3. 2019-01-30 14:58:11.685449 [DEBUG] sofia.c:9746 sofia/default/0117896884@172.31.32.71 receiving invite from 172.31.42.61:5060 version: 1.6.13  64bit
  4. 2019-01-30 14:58:11.685449 [DEBUG] sofia.c:9858 IP 172.31.42.61 Approved by acl "default[]". Access Granted.
  5. 2019-01-30 14:58:11.685449 [DEBUG] sofia.c:7014 Channel sofia/default/0117896884@172.31.32.71 entering state [received][100]
  6. 2019-01-30 14:58:11.685449 [DEBUG] sofia.c:7024 Remote SDP:
  7. v=0
  8. o=FreeSWITCH 1548835251 1548835252 IN IP4 172.31.42.61
  9. s=FreeSWITCH
  10. c=IN IP4 172.31.42.61
  11. t=0 0
  12. m=audio 19154 RTP/AVP 0 101 13
  13. a=rtpmap:0 PCMU/8000
  14. a=rtpmap:101 telephone-event/8000
  15. a=fmtp:101 0-16
  16. a=ptime:20
  17.  
  18. 2019-01-30 14:58:11.685449 [DEBUG] switch_core_media.c:4344 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G729:18:8000:20:8000:1]
  19. 2019-01-30 14:58:11.685449 [DEBUG] switch_core_media.c:4344 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  20. 2019-01-30 14:58:11.685449 [DEBUG] switch_core_media.c:4373 Bah HUMBUG! Sticking with PCMU@8000h@20i
  21. 2019-01-30 14:58:11.685449 [DEBUG] switch_core_media.c:4399 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
  22. 2019-01-30 14:58:11.685449 [DEBUG] switch_core_media.c:4344 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  23. 2019-01-30 14:58:11.685449 [DEBUG] switch_core_media.c:4260 Set telephone-event payload to 101@8000
  24. 2019-01-30 14:58:11.685449 [DEBUG] switch_core_media.c:3043 Set Codec sofia/default/0117896884@172.31.32.71 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
  25. 2019-01-30 14:58:11.685449 [DEBUG] switch_core_codec.c:111 sofia/default/0117896884@172.31.32.71 Original read codec set to PCMU:0
  26. 2019-01-30 14:58:11.685449 [DEBUG] switch_core_media.c:4603 Set telephone-event payload to 101@8000
  27. 2019-01-30 14:58:11.685449 [DEBUG] switch_core_media.c:4662 sofia/default/0117896884@172.31.32.71 Set 2833 dtmf send payload to 101 recv payload to 101
  28. 2019-01-30 14:58:11.685449 [DEBUG] sofia.c:7413 (sofia/default/0117896884@172.31.32.71) State Change CS_NEW -> CS_INIT
  29. 2019-01-30 14:58:11.685449 [DEBUG] switch_core_state_machine.c:603 (sofia/default/0117896884@172.31.32.71) State NEW
  30. 2019-01-30 14:58:11.685449 [DEBUG] switch_core_state_machine.c:584 (sofia/default/0117896884@172.31.32.71) Running State Change CS_INIT (Cur 1 Tot 142006)
  31. 2019-01-30 14:58:11.685449 [DEBUG] switch_core_state_machine.c:627 (sofia/default/0117896884@172.31.32.71) State INIT
  32. 2019-01-30 14:58:11.685449 [DEBUG] mod_sofia.c:90 sofia/default/0117896884@172.31.32.71 SOFIA INIT
  33. 2019-01-30 14:58:11.685449 [DEBUG] switch_core_state_machine.c:40 sofia/default/0117896884@172.31.32.71 Standard INIT
  34. 2019-01-30 14:58:11.685449 [DEBUG] switch_core_state_machine.c:48 (sofia/default/0117896884@172.31.32.71) State Change CS_INIT -> CS_ROUTING
  35. 2019-01-30 14:58:11.685449 [DEBUG] switch_core_state_machine.c:627 (sofia/default/0117896884@172.31.32.71) State INIT going to sleep
  36. 2019-01-30 14:58:11.685449 [DEBUG] switch_core_state_machine.c:584 (sofia/default/0117896884@172.31.32.71) Running State Change CS_ROUTING (Cur 1 Tot 142006)
  37. 2019-01-30 14:58:11.685449 [DEBUG] switch_channel.c:2249 (sofia/default/0117896884@172.31.32.71) Callstate Change DOWN -> RINGING
  38. 2019-01-30 14:58:11.685449 [DEBUG] switch_core_state_machine.c:643 (sofia/default/0117896884@172.31.32.71) State ROUTING
  39. 2019-01-30 14:58:11.685449 [DEBUG] mod_sofia.c:143 sofia/default/0117896884@172.31.32.71 SOFIA ROUTING
  40. 2019-01-30 14:58:11.685449 [DEBUG] switch_core_state_machine.c:236 sofia/default/0117896884@172.31.32.71 Standard ROUTING
  41. 2019-01-30 14:58:11.685449 [INFO] mod_dialplan_xml.c:637 Processing 0117896884 <0117896884>->999990117896884 in context default
  42. Dialplan: sofia/default/0117896884@172.31.32.71 parsing [default->CustomVoicemail] continue=false
  43. Dialplan: sofia/default/0117896884@172.31.32.71 Regex (PASS) [CustomVoicemail] destination_number(999990117896884) =~ /^[a-zA-Z0-9_.-]*$/ break=on-false
  44. Dialplan: sofia/default/0117896884@172.31.32.71 Action set(send_silence_when_idle=400)
  45. Dialplan: sofia/default/0117896884@172.31.32.71 Action answer()
  46. Dialplan: sofia/default/0117896884@172.31.32.71 Action sleep(2000)
  47. Dialplan: sofia/default/0117896884@172.31.32.71 Action lua(astpp.dialplan.lua)
  48. 2019-01-30 14:58:11.685449 [DEBUG] switch_core_state_machine.c:286 (sofia/default/0117896884@172.31.32.71) State Change CS_ROUTING -> CS_EXECUTE
  49. 2019-01-30 14:58:11.685449 [DEBUG] switch_core_state_machine.c:643 (sofia/default/0117896884@172.31.32.71) State ROUTING going to sleep
  50. 2019-01-30 14:58:11.685449 [DEBUG] switch_core_state_machine.c:584 (sofia/default/0117896884@172.31.32.71) Running State Change CS_EXECUTE (Cur 1 Tot 142006)
  51. 2019-01-30 14:58:11.685449 [DEBUG] switch_core_state_machine.c:650 (sofia/default/0117896884@172.31.32.71) State EXECUTE
  52. 2019-01-30 14:58:11.685449 [DEBUG] mod_sofia.c:198 sofia/default/0117896884@172.31.32.71 SOFIA EXECUTE
  53. 2019-01-30 14:58:11.685449 [DEBUG] switch_core_state_machine.c:328 sofia/default/0117896884@172.31.32.71 Standard EXECUTE
  54. EXECUTE sofia/default/0117896884@172.31.32.71 set(send_silence_when_idle=400)
  55. 2019-01-30 14:58:11.685449 [DEBUG] mod_dptools.c:1527 SET sofia/default/0117896884@172.31.32.71 [send_silence_when_idle]=[400]
  56. EXECUTE sofia/default/0117896884@172.31.32.71 answer()
  57. 2019-01-30 14:58:11.685449 [DEBUG] switch_core_media.c:6640 AUDIO RTP [sofia/default/0117896884@172.31.32.71] 172.31.32.71 port 21534 -> 172.31.42.61 port 19154 codec: 0 ms: 20
  58. 2019-01-30 14:58:11.685449 [DEBUG] switch_rtp.c:3878 Starting timer [soft] 160 bytes per 20ms
  59. 2019-01-30 14:58:11.705435 [DEBUG] switch_rtp.c:7976 Activate VAD codec PCMU 20ms
  60. 2019-01-30 14:58:11.705435 [DEBUG] switch_core_media.c:6813 AUDIO RTP Engage VAD for sofia/default/0117896884@172.31.32.71 ( in  )
  61. 2019-01-30 14:58:11.705435 [DEBUG] switch_core_media.c:6946 sofia/default/0117896884@172.31.32.71 Set 2833 dtmf send payload to 101
  62. 2019-01-30 14:58:11.705435 [DEBUG] switch_core_media.c:6953 sofia/default/0117896884@172.31.32.71 Set 2833 dtmf receive payload to 101
  63. 2019-01-30 14:58:11.705435 [DEBUG] switch_core_media.c:6976 sofia/default/0117896884@172.31.32.71 Set rtp dtmf delay to 40
  64. 2019-01-30 14:58:11.705435 [DEBUG] mod_sofia.c:822 Local SDP sofia/default/0117896884@172.31.32.71:
  65. v=0
  66. o=FreeSWITCH 1548831557 1548831558 IN IP4 172.31.32.71
  67. s=FreeSWITCH
  68. c=IN IP4 172.31.32.71
  69. t=0 0
  70. m=audio 21534 RTP/AVP 0 101
  71. a=rtpmap:0 PCMU/8000
  72. a=rtpmap:101 telephone-event/8000
  73. a=fmtp:101 0-16
  74. a=fmtp:18 annexb=no
  75. a=ptime:20
  76. a=sendrecv
  77.  
  78. 2019-01-30 14:58:11.705435 [NOTICE] mod_dptools.c:1309 Channel [sofia/default/0117896884@172.31.32.71] has been answered
  79. 2019-01-30 14:58:11.705435 [DEBUG] switch_channel.c:3772 (sofia/default/0117896884@172.31.32.71) Callstate Change RINGING -> ACTIVE
  80. 2019-01-30 14:58:11.705435 [DEBUG] sofia.c:7014 Channel sofia/default/0117896884@172.31.32.71 entering state [completed][200]
  81. EXECUTE sofia/default/0117896884@172.31.32.71 sleep(2000)
  82. 2019-01-30 14:58:11.705435 [DEBUG] switch_ivr.c:195 Codec Activated L16@8000hz 1 channels 20ms
  83. 2019-01-30 14:58:11.705435 [DEBUG] sofia.c:7014 Channel sofia/default/0117896884@172.31.32.71 entering state [ready][200]
  84. 2019-01-30 14:58:12.085443 [DEBUG] switch_rtp.c:6970 Correct audio ip/port confirmed.
  85. EXECUTE sofia/default/0117896884@172.31.32.71 lua(astpp.dialplan.lua)
  86. 2019-01-30 14:58:13.725435 [INFO] switch_cpp.cpp:1360 ===============================FAX APPLICATION========================!!!
  87. EXECUTE sofia/default/0117896884@172.31.32.71 set(fax_enable_t38_request=true)
  88. 2019-01-30 14:58:13.725435 [DEBUG] mod_dptools.c:1527 SET sofia/default/0117896884@172.31.32.71 [fax_enable_t38_request]=[true]
  89. EXECUTE sofia/default/0117896884@172.31.32.71 set(fax_enable_t38=true)
  90. 2019-01-30 14:58:13.725435 [DEBUG] mod_dptools.c:1527 SET sofia/default/0117896884@172.31.32.71 [fax_enable_t38]=[true]
  91. EXECUTE sofia/default/0117896884@172.31.32.71 set(t38_passthru=true)
  92. 2019-01-30 14:58:13.725435 [DEBUG] mod_dptools.c:1527 SET sofia/default/0117896884@172.31.32.71 [t38_passthru]=[true]
  93. EXECUTE sofia/default/0117896884@172.31.32.71 set(session_in_hangup_hook=true)
  94. 2019-01-30 14:58:13.725435 [DEBUG] mod_dptools.c:1527 SET sofia/default/0117896884@172.31.32.71 [session_in_hangup_hook]=[true]
  95. EXECUTE sofia/default/0117896884@172.31.32.71 rxfax(/tmp/f584c9b5-b274-4348-b31d-d2232a1f6272-FAX.tif)
  96. 2019-01-30 14:58:13.725435 [DEBUG] mod_spandsp_fax.c:1440 Raw read codec activation Success L16 20000
  97. 2019-01-30 14:58:13.725435 [DEBUG] switch_core_codec.c:223 sofia/default/0117896884@172.31.32.71 Push codec L16:100
  98. 2019-01-30 14:58:13.725435 [DEBUG] mod_spandsp_fax.c:1458 Raw write codec activation Success L16
  99. 2019-01-30 14:58:13.725435 [DEBUG] switch_ivr.c:195 Codec Activated L16@8000hz 1 channels 20ms
  100. 2019-01-30 14:58:14.045435 [DEBUG] sofia.c:7014 Channel sofia/default/0117896884@172.31.32.71 entering state [received][100]
  101. 2019-01-30 14:58:14.045435 [DEBUG] sofia.c:7024 Remote SDP:
  102. v=0
  103. o=FreeSWITCH 1548835251 1548835253 IN IP4 172.31.42.61
  104. s=FreeSWITCH
  105. c=IN IP4 172.31.42.61
  106. t=0 0
  107. m=image 19154 udptl t38
  108. a=T38FaxVersion:0
  109. a=T38MaxBitRate:14400
  110. a=T38FaxFillBitRemoval
  111. a=T38FaxRateManagement:transferredTCF
  112. a=T38FaxMaxBuffer:2000
  113. a=T38FaxMaxDatagram:400
  114. a=T38FaxUdpEC:t38UDPRedundancy
  115.  
  116. 2019-01-30 14:58:14.065422 [DEBUG] mod_spandsp_fax.c:1037 T38 SDP Origin = FreeSWITCH
  117. 2019-01-30 14:58:14.065422 [DEBUG] mod_spandsp_fax.c:1038 T38FaxVersion = 0
  118. 2019-01-30 14:58:14.065422 [DEBUG] mod_spandsp_fax.c:1039 T38MaxBitRate = 14400
  119. 2019-01-30 14:58:14.065422 [DEBUG] mod_spandsp_fax.c:1040 T38FaxFillBitRemoval = 1
  120. 2019-01-30 14:58:14.065422 [DEBUG] mod_spandsp_fax.c:1041 T38FaxTranscodingMMR = 0
  121. 2019-01-30 14:58:14.065422 [DEBUG] mod_spandsp_fax.c:1042 T38FaxTranscodingJBIG = 0
  122. 2019-01-30 14:58:14.065422 [DEBUG] mod_spandsp_fax.c:1043 T38FaxRateManagement = 'transferredTCF'
  123. 2019-01-30 14:58:14.065422 [DEBUG] mod_spandsp_fax.c:1044 T38FaxMaxBuffer = 2000
  124. 2019-01-30 14:58:14.065422 [DEBUG] mod_spandsp_fax.c:1045 T38FaxMaxDatagram = 400
  125. 2019-01-30 14:58:14.065422 [DEBUG] mod_spandsp_fax.c:1046 T38FaxUdpEC = 't38UDPRedundancy'
  126. 2019-01-30 14:58:14.065422 [DEBUG] mod_spandsp_fax.c:1047 T38VendorInfo = ''
  127. 2019-01-30 14:58:14.065422 [DEBUG] mod_spandsp_fax.c:1048 ip = '172.31.42.61'
  128. 2019-01-30 14:58:14.065422 [DEBUG] mod_spandsp_fax.c:1050 port = 19154
  129. 2019-01-30 14:58:14.065422 [DEBUG] switch_core_media.c:9506 Remote address:port [172.31.42.61:19154] has not changed.
  130. 2019-01-30 14:58:14.065422 [DEBUG] switch_core_media.c:9145 sofia/default/0117896884@172.31.32.71 image media sdp:
  131. v=0
  132. o=FreeSWITCH 1548831557 1548831559 IN IP4 172.31.32.71
  133. s=FreeSWITCH
  134. c=IN IP4 172.31.32.71
  135. t=0 0
  136. m=image 21534 udptl t38
  137. a=T38FaxVersion:0
  138. a=T38MaxBitRate:14400
  139. a=T38FaxFillBitRemoval
  140. a=T38FaxRateManagement:transferredTCF
  141. a=T38FaxMaxBuffer:2000
  142. a=T38FaxMaxDatagram:400
  143. a=T38FaxUdpEC:t38UDPRedundancy
  144.  
  145. 2019-01-30 14:58:14.065422 [DEBUG] switch_core_media.c:9506 Remote address:port [172.31.42.61:19154] has not changed.
  146. 2019-01-30 14:58:14.065422 [DEBUG] sofia.c:7014 Channel sofia/default/0117896884@172.31.32.71 entering state [completed][200]
  147. 2019-01-30 14:58:14.085422 [DEBUG] sofia.c:7014 Channel sofia/default/0117896884@172.31.32.71 entering state [ready][200]
  148. 2019-01-30 14:58:21.705451 [DEBUG] mod_spandsp_fax.c:317 === Negotiation Result =======================================================
  149. 2019-01-30 14:58:21.705451 [DEBUG] mod_spandsp_fax.c:318 Remote station id: SpanDSP Fax Ident
  150. 2019-01-30 14:58:21.705451 [DEBUG] mod_spandsp_fax.c:319 Local station id:  SpanDSP Fax Ident
  151. 2019-01-30 14:58:21.705451 [DEBUG] mod_spandsp_fax.c:320 Transfer Rate:     14400
  152. 2019-01-30 14:58:21.705451 [DEBUG] mod_spandsp_fax.c:322 ECM status         on
  153. 2019-01-30 14:58:21.705451 [DEBUG] mod_spandsp_fax.c:323 remote country:  
  154. 2019-01-30 14:58:21.705451 [DEBUG] mod_spandsp_fax.c:324 remote vendor:    
  155. 2019-01-30 14:58:21.705451 [DEBUG] mod_spandsp_fax.c:325 remote model:    
  156. 2019-01-30 14:58:21.705451 [DEBUG] mod_spandsp_fax.c:327 ==============================================================================
  157. 2019-01-30 14:58:55.585432 [DEBUG] mod_spandsp_fax.c:428 ==== Page Received ===========================================================
  158. 2019-01-30 14:58:55.585432 [DEBUG] mod_spandsp_fax.c:429 Page no = 1
  159. 2019-01-30 14:58:55.585432 [DEBUG] mod_spandsp_fax.c:430 Image type = bi-level (bi-level in the file)
  160. 2019-01-30 14:58:55.585432 [DEBUG] mod_spandsp_fax.c:431 Image size = 1728 x 2156 pixels (1728 x 2156 pixels in the file)
  161. 2019-01-30 14:58:55.585432 [DEBUG] mod_spandsp_fax.c:432 Image resolution = 8040/m x 7700/m (8040/m x 7700/m in the file)
  162. 2019-01-30 14:58:55.585432 [DEBUG] mod_spandsp_fax.c:433 Compression = T.85(L0) (32)
  163. 2019-01-30 14:58:55.585432 [DEBUG] mod_spandsp_fax.c:434 Compressed image size = 46632 bytes
  164. 2019-01-30 14:58:55.585432 [DEBUG] mod_spandsp_fax.c:435 Bad rows = 0
  165. 2019-01-30 14:58:55.585432 [DEBUG] mod_spandsp_fax.c:436 Longest bad row run = 0
  166. 2019-01-30 14:58:55.585432 [DEBUG] mod_spandsp_fax.c:437 ==============================================================================
  167. 2019-01-30 14:58:57.945459 [DEBUG] mod_spandsp_fax.c:496 ==============================================================================
  168. 2019-01-30 14:58:57.945459 [DEBUG] mod_spandsp_fax.c:502 Fax successfully received.
  169. 2019-01-30 14:58:57.945459 [DEBUG] mod_spandsp_fax.c:513 Remote station id: SpanDSP Fax Ident
  170. 2019-01-30 14:58:57.945459 [DEBUG] mod_spandsp_fax.c:514 Local station id:  SpanDSP Fax Ident
  171. 2019-01-30 14:58:57.945459 [DEBUG] mod_spandsp_fax.c:515 Pages transferred: 1
  172. 2019-01-30 14:58:57.945459 [DEBUG] mod_spandsp_fax.c:517 Total fax pages:   1
  173. 2019-01-30 14:58:57.945459 [DEBUG] mod_spandsp_fax.c:518 Image resolution:  8040x7700
  174. 2019-01-30 14:58:57.945459 [DEBUG] mod_spandsp_fax.c:519 Transfer Rate:     14400
  175. 2019-01-30 14:58:57.945459 [DEBUG] mod_spandsp_fax.c:521 ECM status         on
  176. 2019-01-30 14:58:57.945459 [DEBUG] mod_spandsp_fax.c:522 remote country:  
  177. 2019-01-30 14:58:57.945459 [DEBUG] mod_spandsp_fax.c:523 remote vendor:    
  178. 2019-01-30 14:58:57.945459 [DEBUG] mod_spandsp_fax.c:524 remote model:    
  179. 2019-01-30 14:58:57.945459 [DEBUG] mod_spandsp_fax.c:526 ==============================================================================
  180. 2019-01-30 14:58:57.945459 [DEBUG] switch_core_codec.c:248 sofia/default/0117896884@172.31.32.71 Restore previous codec PCMU:0.
  181. EXECUTE sofia/default/0117896884@172.31.32.71 set(api_hangup_hook=system /var/www/html/astpp/FAX/scripts/emailfax.sh /tmp/f584c9b5-b274-4348-b31d-d2232a1f6272-FAX.tif 0117896884 Hardik devang.nathwani%40inextrix.com /tmp/f584c9b5-b274-4348-b31d-d2232a1f6272-FAX.tif)
  182. 2019-01-30 14:58:57.945459 [DEBUG] mod_dptools.c:1527 SET sofia/default/0117896884@172.31.32.71 [api_hangup_hook]=[system /var/www/html/astpp/FAX/scripts/emailfax.sh /tmp/f584c9b5-b274-4348-b31d-d2232a1f6272-FAX.tif 0117896884 Hardik devang.nathwani%40inextrix.com /tmp/f584c9b5-b274-4348-b31d-d2232a1f6272-FAX.tif]
  183. 2019-01-30 14:58:57.945459 [INFO] switch_cpp.cpp:1360 =======================================================================!!!
  184. 2019-01-30 14:58:57.945459 [DEBUG] switch_cpp.cpp:722 CoreSession::hangup
  185. 2019-01-30 14:58:57.945459 [NOTICE] switch_cpp.cpp:724 Hangup sofia/default/0117896884@172.31.32.71 [CS_EXECUTE] [NORMAL_CLEARING]
  186. 2019-01-30 14:58:57.945459 [DEBUG] switch_cpp.cpp:1107 sofia/default/0117896884@172.31.32.71 destroy/unlink session from object
  187. 2019-01-30 14:58:57.945459 [DEBUG] switch_core_session.c:2797 sofia/default/0117896884@172.31.32.71 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
  188. 2019-01-30 14:58:57.945459 [DEBUG] switch_core_state_machine.c:650 (sofia/default/0117896884@172.31.32.71) State EXECUTE going to sleep
  189. 2019-01-30 14:58:57.945459 [DEBUG] switch_core_state_machine.c:584 (sofia/default/0117896884@172.31.32.71) Running State Change CS_HANGUP (Cur 1 Tot 142006)
  190. 2019-01-30 14:58:57.945459 [DEBUG] switch_core_state_machine.c:850 (sofia/default/0117896884@172.31.32.71) Callstate Change ACTIVE -> HANGUP
  191. 2019-01-30 14:58:57.945459 [DEBUG] switch_core_state_machine.c:852 (sofia/default/0117896884@172.31.32.71) State HANGUP
  192. 2019-01-30 14:58:57.945459 [DEBUG] mod_sofia.c:438 Channel sofia/default/0117896884@172.31.32.71 hanging up, cause: NORMAL_CLEARING
  193. 2019-01-30 14:58:57.945459 [DEBUG] mod_sofia.c:491 Sending BYE to sofia/default/0117896884@172.31.32.71
  194. 2019-01-30 14:58:57.945459 [DEBUG] switch_core_state_machine.c:60 sofia/default/0117896884@172.31.32.71 Standard HANGUP, cause: NORMAL_CLEARING
  195. 2019-01-30 14:58:57.945459 [DEBUG] switch_core_state_machine.c:852 (sofia/default/0117896884@172.31.32.71) State HANGUP going to sleep
  196. 2019-01-30 14:58:59.805425 [DEBUG] switch_core_state_machine.c:783 Hangup Command with Session system(/var/www/html/astpp/FAX/scripts/emailfax.sh /tmp/f584c9b5-b274-4348-b31d-d2232a1f6272-FAX.tif 0117896884 Hardik devang.nathwani%40inextrix.com /tmp/f584c9b5-b274-4348-b31d-d2232a1f6272-FAX.tif):
  197.  
  198.  
  199. 2019-01-30 14:58:59.805425 [DEBUG] switch_core_state_machine.c:619 (sofia/default/0117896884@172.31.32.71) State Change CS_HANGUP -> CS_REPORTING
  200. 2019-01-30 14:58:59.805425 [DEBUG] switch_core_state_machine.c:584 (sofia/default/0117896884@172.31.32.71) Running State Change CS_REPORTING (Cur 1 Tot 142006)
  201. 2019-01-30 14:58:59.805425 [DEBUG] switch_core_state_machine.c:938 (sofia/default/0117896884@172.31.32.71) State REPORTING
  202. 2019-01-30 14:58:59.805425 [DEBUG] switch_core_state_machine.c:174 sofia/default/0117896884@172.31.32.71 Standard REPORTING, cause: NORMAL_CLEARING
  203. 2019-01-30 14:58:59.805425 [DEBUG] switch_core_state_machine.c:938 (sofia/default/0117896884@172.31.32.71) State REPORTING going to sleep
  204. 2019-01-30 14:58:59.805425 [DEBUG] switch_core_state_machine.c:610 (sofia/default/0117896884@172.31.32.71) State Change CS_REPORTING -> CS_DESTROY
  205. 2019-01-30 14:58:59.805425 [DEBUG] switch_core_session.c:1647 Session 142006 (sofia/default/0117896884@172.31.32.71) Locked, Waiting on external entities
  206. 2019-01-30 14:58:59.805425 [NOTICE] switch_core_session.c:1665 Session 142006 (sofia/default/0117896884@172.31.32.71) Ended
  207. 2019-01-30 14:58:59.805425 [NOTICE] switch_core_session.c:1669 Close Channel sofia/default/0117896884@172.31.32.71 [CS_DESTROY]
  208. 2019-01-30 14:58:59.805425 [DEBUG] switch_core_state_machine.c:741 (sofia/default/0117896884@172.31.32.71) Running State Change CS_DESTROY (Cur 0 Tot 142006)
  209. 2019-01-30 14:58:59.805425 [DEBUG] switch_core_state_machine.c:751 (sofia/default/0117896884@172.31.32.71) State DESTROY
  210. 2019-01-30 14:58:59.805425 [DEBUG] mod_sofia.c:343 sofia/default/0117896884@172.31.32.71 SOFIA DESTROY
  211. 2019-01-30 14:58:59.805425 [DEBUG] switch_core_state_machine.c:181 sofia/default/0117896884@172.31.32.71 Standard DESTROY
  212. 2019-01-30 14:58:59.805425 [DEBUG] switch_core_state_machine.c:751 (sofia/default/0117896884@172.31.32.71) State DESTROY going to sleep
  213. 2019-01-30 14:59:05.265446 [WARNING] sofia_reg.c:1792 SIP auth challenge (REGISTER) on sofia profile 'default' for [30208215@172.31.32.71] from ip 172.31.38.3
  214.