From Mungo Ibis, 2 Years ago, written in FreeSWITCH.
- view diff
Embed
  1. freeswitch@BetaQA>
  2. 2022-10-10 11:24:03.743531 28.90% [DEBUG] switch_ivr_originate.c:2281 Parsing global variables
  3. 2022-10-10 11:24:03.743531 28.90% [NOTICE] switch_channel.c:1123 New Channel sofia/default/8485860527@142.132.184.134:5076 [9a26ab61-7191-472d-bb43-b3b615719f12]
  4. 2022-10-10 11:24:03.743531 28.90% [DEBUG] mod_sofia.c:5121 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_NEW -> CS_INIT
  5. 2022-10-10 11:24:03.743531 28.90% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_INIT (Cur 1 Tot 22250)
  6. 2022-10-10 11:24:03.743531 28.90% [DEBUG] switch_core_state_machine.c:624 (sofia/default/8485860527@142.132.184.134:5076) State INIT
  7. 2022-10-10 11:24:03.743531 28.90% [DEBUG] mod_sofia.c:97 sofia/default/8485860527@142.132.184.134:5076 SOFIA INIT
  8. 2022-10-10 11:24:03.743531 28.90% [INFO] sofia_glue.c:1651 sofia/default/8485860527@142.132.184.134:5076 sending invite call-id: (null)
  9. 2022-10-10 11:24:03.743531 28.90% [DEBUG] sofia_glue.c:1654 sofia/default/8485860527@142.132.184.134:5076 sending invite version: 1.10.7 -release 64bit
  10. Local SDP:
  11. v=0
  12. o=FreeSWITCH 1665383577 1665383578 IN IP4 142.132.184.134
  13. s=FreeSWITCH
  14. c=IN IP4 142.132.184.134
  15. t=0 0
  16. m=audio 17466 RTP/AVP 8 0 101
  17. a=rtpmap:8 PCMA/8000
  18. a=rtpmap:0 PCMU/8000
  19. a=rtpmap:101 telephone-event/8000
  20. a=fmtp:101 0-15
  21. a=ptime:20
  22. a=sendrecv
  23.  
  24. 2022-10-10 11:24:03.743531 28.90% [DEBUG] switch_core_state_machine.c:40 sofia/default/8485860527@142.132.184.134:5076 Standard INIT
  25. 2022-10-10 11:24:03.743531 28.90% [DEBUG] switch_core_state_machine.c:48 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_INIT -> CS_ROUTING
  26. 2022-10-10 11:24:03.743531 28.90% [DEBUG] switch_core_state_machine.c:624 (sofia/default/8485860527@142.132.184.134:5076) State INIT going to sleep
  27. 2022-10-10 11:24:03.743531 28.90% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_ROUTING (Cur 1 Tot 22250)
  28. 2022-10-10 11:24:03.743531 28.90% [DEBUG] switch_core_state_machine.c:640 (sofia/default/8485860527@142.132.184.134:5076) State ROUTING
  29. 2022-10-10 11:24:03.743531 28.90% [DEBUG] mod_sofia.c:158 sofia/default/8485860527@142.132.184.134:5076 SOFIA ROUTING
  30. 2022-10-10 11:24:03.743531 28.90% [DEBUG] switch_ivr_originate.c:67 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_ROUTING -> CS_CONSUME_MEDIA
  31. 2022-10-10 11:24:03.743531 28.90% [DEBUG] switch_core_state_machine.c:640 (sofia/default/8485860527@142.132.184.134:5076) State ROUTING going to sleep
  32. 2022-10-10 11:24:03.743531 28.90% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_CONSUME_MEDIA (Cur 1 Tot 22250)
  33. 2022-10-10 11:24:03.743531 28.90% [DEBUG] switch_core_state_machine.c:659 (sofia/default/8485860527@142.132.184.134:5076) State CONSUME_MEDIA
  34. 2022-10-10 11:24:03.743531 28.90% [DEBUG] switch_core_state_machine.c:659 (sofia/default/8485860527@142.132.184.134:5076) State CONSUME_MEDIA going to sleep
  35. 2022-10-10 11:24:03.743531 28.90% [DEBUG] sofia.c:7499 Channel sofia/default/8485860527@142.132.184.134:5076 entering state [calling][0]
  36. 2022-10-10 11:24:08.423539 33.17% [NOTICE] sofia_reg.c:459 Registering 7986208696
  37. 2022-10-10 11:24:08.683565 33.17% [ERR] sofia_reg.c:2677 7986208696 Failed Registration with status Forbidden [403]. failure #5
  38. 2022-10-10 11:24:09.423554 34.07% [WARNING] sofia_reg.c:516 7986208696 Failed Registration [403], setting retry to 150 seconds.
  39. 2022-10-10 11:24:10.443542 35.03% [DEBUG] switch_ivr_originate.c:2281 Parsing global variables
  40. 2022-10-10 11:24:10.443542 35.03% [NOTICE] switch_channel.c:1123 New Channel sofia/default/8485860527@142.132.184.134:5076 [8e7d0da0-a490-47fb-943a-27e64199136b]
  41. 2022-10-10 11:24:10.443542 35.03% [DEBUG] mod_sofia.c:5121 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_NEW -> CS_INIT
  42. 2022-10-10 11:24:10.443542 35.03% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_INIT (Cur 2 Tot 22251)
  43. 2022-10-10 11:24:10.443542 35.03% [DEBUG] switch_core_state_machine.c:624 (sofia/default/8485860527@142.132.184.134:5076) State INIT
  44. 2022-10-10 11:24:10.443542 35.03% [DEBUG] mod_sofia.c:97 sofia/default/8485860527@142.132.184.134:5076 SOFIA INIT
  45. 2022-10-10 11:24:10.443542 35.03% [INFO] sofia_glue.c:1651 sofia/default/8485860527@142.132.184.134:5076 sending invite call-id: (null)
  46. 2022-10-10 11:24:10.443542 35.03% [DEBUG] sofia_glue.c:1654 sofia/default/8485860527@142.132.184.134:5076 sending invite version: 1.10.7 -release 64bit
  47. Local SDP:
  48. v=0
  49. o=FreeSWITCH 1665376434 1665376435 IN IP4 142.132.184.134
  50. s=FreeSWITCH
  51. c=IN IP4 142.132.184.134
  52. t=0 0
  53. m=audio 24616 RTP/AVP 8 0 101
  54. a=rtpmap:8 PCMA/8000
  55. a=rtpmap:0 PCMU/8000
  56. a=rtpmap:101 telephone-event/8000
  57. a=fmtp:101 0-15
  58. a=ptime:20
  59. a=sendrecv
  60.  
  61. 2022-10-10 11:24:10.443542 35.03% [DEBUG] switch_core_state_machine.c:40 sofia/default/8485860527@142.132.184.134:5076 Standard INIT
  62. 2022-10-10 11:24:10.443542 35.03% [DEBUG] switch_core_state_machine.c:48 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_INIT -> CS_ROUTING
  63. 2022-10-10 11:24:10.443542 35.03% [DEBUG] switch_core_state_machine.c:624 (sofia/default/8485860527@142.132.184.134:5076) State INIT going to sleep
  64. 2022-10-10 11:24:10.443542 35.03% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_ROUTING (Cur 2 Tot 22251)
  65. 2022-10-10 11:24:10.443542 35.03% [DEBUG] switch_core_state_machine.c:640 (sofia/default/8485860527@142.132.184.134:5076) State ROUTING
  66. 2022-10-10 11:24:10.443542 35.03% [DEBUG] mod_sofia.c:158 sofia/default/8485860527@142.132.184.134:5076 SOFIA ROUTING
  67. 2022-10-10 11:24:10.443542 35.03% [DEBUG] switch_ivr_originate.c:67 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_ROUTING -> CS_CONSUME_MEDIA
  68. 2022-10-10 11:24:10.443542 35.03% [DEBUG] switch_core_state_machine.c:640 (sofia/default/8485860527@142.132.184.134:5076) State ROUTING going to sleep
  69. 2022-10-10 11:24:10.443542 35.03% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 22251)
  70. 2022-10-10 11:24:10.443542 35.03% [DEBUG] switch_core_state_machine.c:659 (sofia/default/8485860527@142.132.184.134:5076) State CONSUME_MEDIA
  71. 2022-10-10 11:24:10.443542 35.03% [DEBUG] switch_core_state_machine.c:659 (sofia/default/8485860527@142.132.184.134:5076) State CONSUME_MEDIA going to sleep
  72. 2022-10-10 11:24:10.443542 35.03% [DEBUG] sofia.c:7499 Channel sofia/default/8485860527@142.132.184.134:5076 entering state [calling][0]
  73. 2022-10-10 11:24:11.403532 36.00% [ERR] sofia_reg.c:2677 6803528347 Failed Registration with status Request Timeout [408]. failure #4
  74. 2022-10-10 11:24:11.403532 36.00% [ERR] sofia_reg.c:2677 9814047798 Failed Registration with status Request Timeout [408]. failure #4
  75. 2022-10-10 11:24:11.423527 36.00% [WARNING] sofia_reg.c:516 6803528347 Failed Registration [408], setting retry to 120 seconds.
  76. 2022-10-10 11:24:11.423527 36.00% [WARNING] sofia_reg.c:516 9814047798 Failed Registration [408], setting retry to 120 seconds.
  77. 2022-10-10 11:24:12.143527 37.07% [DEBUG] switch_ivr_originate.c:2281 Parsing global variables
  78. 2022-10-10 11:24:12.143527 37.07% [NOTICE] switch_channel.c:1123 New Channel sofia/default/8485860527@142.132.184.134:5076 [79c2c4d2-92ef-4d38-9904-89727ac551d3]
  79. 2022-10-10 11:24:12.143527 37.07% [DEBUG] mod_sofia.c:5121 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_NEW -> CS_INIT
  80. 2022-10-10 11:24:12.143527 37.07% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_INIT (Cur 3 Tot 22252)
  81. 2022-10-10 11:24:12.143527 37.07% [DEBUG] switch_core_state_machine.c:624 (sofia/default/8485860527@142.132.184.134:5076) State INIT
  82. 2022-10-10 11:24:12.143527 37.07% [DEBUG] mod_sofia.c:97 sofia/default/8485860527@142.132.184.134:5076 SOFIA INIT
  83. 2022-10-10 11:24:12.143527 37.07% [INFO] sofia_glue.c:1651 sofia/default/8485860527@142.132.184.134:5076 sending invite call-id: (null)
  84. 2022-10-10 11:24:12.143527 37.07% [DEBUG] sofia_glue.c:1654 sofia/default/8485860527@142.132.184.134:5076 sending invite version: 1.10.7 -release 64bit
  85. Local SDP:
  86. v=0
  87. o=FreeSWITCH 1665375516 1665375517 IN IP4 142.132.184.134
  88. s=FreeSWITCH
  89. c=IN IP4 142.132.184.134
  90. t=0 0
  91. m=audio 25536 RTP/AVP 8 0 101
  92. a=rtpmap:8 PCMA/8000
  93. a=rtpmap:0 PCMU/8000
  94. a=rtpmap:101 telephone-event/8000
  95. a=fmtp:101 0-15
  96. a=ptime:20
  97. a=sendrecv
  98.  
  99. 2022-10-10 11:24:12.143527 37.07% [DEBUG] switch_core_state_machine.c:40 sofia/default/8485860527@142.132.184.134:5076 Standard INIT
  100. 2022-10-10 11:24:12.143527 37.07% [DEBUG] switch_core_state_machine.c:48 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_INIT -> CS_ROUTING
  101. 2022-10-10 11:24:12.143527 37.07% [DEBUG] switch_core_state_machine.c:624 (sofia/default/8485860527@142.132.184.134:5076) State INIT going to sleep
  102. 2022-10-10 11:24:12.143527 37.07% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_ROUTING (Cur 3 Tot 22252)
  103. 2022-10-10 11:24:12.143527 37.07% [DEBUG] switch_core_state_machine.c:640 (sofia/default/8485860527@142.132.184.134:5076) State ROUTING
  104. 2022-10-10 11:24:12.143527 37.07% [DEBUG] mod_sofia.c:158 sofia/default/8485860527@142.132.184.134:5076 SOFIA ROUTING
  105. 2022-10-10 11:24:12.143527 37.07% [DEBUG] switch_ivr_originate.c:67 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_ROUTING -> CS_CONSUME_MEDIA
  106. 2022-10-10 11:24:12.143527 37.07% [DEBUG] switch_core_state_machine.c:640 (sofia/default/8485860527@142.132.184.134:5076) State ROUTING going to sleep
  107. 2022-10-10 11:24:12.143527 37.07% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_CONSUME_MEDIA (Cur 3 Tot 22252)
  108. 2022-10-10 11:24:12.143527 37.07% [DEBUG] switch_core_state_machine.c:659 (sofia/default/8485860527@142.132.184.134:5076) State CONSUME_MEDIA
  109. 2022-10-10 11:24:12.143527 37.07% [DEBUG] switch_core_state_machine.c:659 (sofia/default/8485860527@142.132.184.134:5076) State CONSUME_MEDIA going to sleep
  110. 2022-10-10 11:24:12.143527 37.07% [DEBUG] sofia.c:7499 Channel sofia/default/8485860527@142.132.184.134:5076 entering state [calling][0]
  111. 2022-10-10 11:24:13.823550 38.10% [DEBUG] switch_ivr_originate.c:2281 Parsing global variables
  112. 2022-10-10 11:24:13.823550 38.10% [NOTICE] switch_channel.c:1123 New Channel sofia/default/8485860527@142.132.184.134:5076 [4ff12a14-ca02-4472-ae06-c069d4defc20]
  113. 2022-10-10 11:24:13.823550 38.10% [DEBUG] mod_sofia.c:5121 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_NEW -> CS_INIT
  114. 2022-10-10 11:24:13.823550 38.10% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_INIT (Cur 4 Tot 22253)
  115. 2022-10-10 11:24:13.823550 38.10% [DEBUG] switch_core_state_machine.c:624 (sofia/default/8485860527@142.132.184.134:5076) State INIT
  116. 2022-10-10 11:24:13.823550 38.10% [DEBUG] mod_sofia.c:97 sofia/default/8485860527@142.132.184.134:5076 SOFIA INIT
  117. 2022-10-10 11:24:13.823550 38.10% [INFO] sofia_glue.c:1651 sofia/default/8485860527@142.132.184.134:5076 sending invite call-id: (null)
  118. 2022-10-10 11:24:13.823550 38.10% [DEBUG] sofia_glue.c:1654 sofia/default/8485860527@142.132.184.134:5076 sending invite version: 1.10.7 -release 64bit
  119. Local SDP:
  120. v=0
  121. o=FreeSWITCH 1665378547 1665378548 IN IP4 142.132.184.134
  122. s=FreeSWITCH
  123. c=IN IP4 142.132.184.134
  124. t=0 0
  125. m=audio 22506 RTP/AVP 8 0 101
  126. a=rtpmap:8 PCMA/8000
  127. a=rtpmap:0 PCMU/8000
  128. a=rtpmap:101 telephone-event/8000
  129. a=fmtp:101 0-15
  130. a=ptime:20
  131. a=sendrecv
  132.  
  133. 2022-10-10 11:24:13.823550 38.10% [DEBUG] switch_core_state_machine.c:40 sofia/default/8485860527@142.132.184.134:5076 Standard INIT
  134. 2022-10-10 11:24:13.823550 38.10% [DEBUG] switch_core_state_machine.c:48 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_INIT -> CS_ROUTING
  135. 2022-10-10 11:24:13.823550 38.10% [DEBUG] switch_core_state_machine.c:624 (sofia/default/8485860527@142.132.184.134:5076) State INIT going to sleep
  136. 2022-10-10 11:24:13.823550 38.10% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_ROUTING (Cur 4 Tot 22253)
  137. 2022-10-10 11:24:13.823550 38.10% [DEBUG] switch_core_state_machine.c:640 (sofia/default/8485860527@142.132.184.134:5076) State ROUTING
  138. 2022-10-10 11:24:13.823550 38.10% [DEBUG] mod_sofia.c:158 sofia/default/8485860527@142.132.184.134:5076 SOFIA ROUTING
  139. 2022-10-10 11:24:13.823550 38.10% [DEBUG] switch_ivr_originate.c:67 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_ROUTING -> CS_CONSUME_MEDIA
  140. 2022-10-10 11:24:13.843541 38.10% [DEBUG] switch_core_state_machine.c:640 (sofia/default/8485860527@142.132.184.134:5076) State ROUTING going to sleep
  141. 2022-10-10 11:24:13.843541 38.10% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_CONSUME_MEDIA (Cur 4 Tot 22253)
  142. 2022-10-10 11:24:13.843541 38.10% [DEBUG] sofia.c:7499 Channel sofia/default/8485860527@142.132.184.134:5076 entering state [calling][0]
  143. 2022-10-10 11:24:13.843541 38.10% [DEBUG] switch_core_state_machine.c:659 (sofia/default/8485860527@142.132.184.134:5076) State CONSUME_MEDIA
  144. 2022-10-10 11:24:13.843541 38.10% [DEBUG] switch_core_state_machine.c:659 (sofia/default/8485860527@142.132.184.134:5076) State CONSUME_MEDIA going to sleep
  145. 2022-10-10 11:24:15.523533 40.07% [DEBUG] switch_ivr_originate.c:2281 Parsing global variables
  146. 2022-10-10 11:24:15.523533 40.07% [NOTICE] switch_channel.c:1123 New Channel sofia/default/8485860527@142.132.184.134:5076 [e1839fcd-f9ad-483b-bee1-33af86bc0726]
  147. 2022-10-10 11:24:15.523533 40.07% [DEBUG] mod_sofia.c:5121 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_NEW -> CS_INIT
  148. 2022-10-10 11:24:15.523533 40.07% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_INIT (Cur 5 Tot 22254)
  149. 2022-10-10 11:24:15.523533 40.07% [DEBUG] switch_core_state_machine.c:624 (sofia/default/8485860527@142.132.184.134:5076) State INIT
  150. 2022-10-10 11:24:15.523533 40.07% [DEBUG] mod_sofia.c:97 sofia/default/8485860527@142.132.184.134:5076 SOFIA INIT
  151. 2022-10-10 11:24:15.523533 40.07% [INFO] sofia_glue.c:1651 sofia/default/8485860527@142.132.184.134:5076 sending invite call-id: (null)
  152. 2022-10-10 11:24:15.523533 40.07% [DEBUG] sofia_glue.c:1654 sofia/default/8485860527@142.132.184.134:5076 sending invite version: 1.10.7 -release 64bit
  153. Local SDP:
  154. v=0
  155. o=FreeSWITCH 1665381865 1665381866 IN IP4 142.132.184.134
  156. s=FreeSWITCH
  157. c=IN IP4 142.132.184.134
  158. t=0 0
  159. m=audio 19190 RTP/AVP 8 0 101
  160. a=rtpmap:8 PCMA/8000
  161. a=rtpmap:0 PCMU/8000
  162. a=rtpmap:101 telephone-event/8000
  163. a=fmtp:101 0-15
  164. a=ptime:20
  165. a=sendrecv
  166.  
  167. 2022-10-10 11:24:15.523533 40.07% [DEBUG] switch_core_state_machine.c:40 sofia/default/8485860527@142.132.184.134:5076 Standard INIT
  168. 2022-10-10 11:24:15.523533 40.07% [DEBUG] switch_core_state_machine.c:48 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_INIT -> CS_ROUTING
  169. 2022-10-10 11:24:15.523533 40.07% [DEBUG] switch_core_state_machine.c:624 (sofia/default/8485860527@142.132.184.134:5076) State INIT going to sleep
  170. 2022-10-10 11:24:15.523533 40.07% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_ROUTING (Cur 5 Tot 22254)
  171. 2022-10-10 11:24:15.523533 40.07% [DEBUG] sofia.c:7499 Channel sofia/default/8485860527@142.132.184.134:5076 entering state [calling][0]
  172. 2022-10-10 11:24:15.523533 40.07% [DEBUG] switch_core_state_machine.c:640 (sofia/default/8485860527@142.132.184.134:5076) State ROUTING
  173. 2022-10-10 11:24:15.523533 40.07% [DEBUG] mod_sofia.c:158 sofia/default/8485860527@142.132.184.134:5076 SOFIA ROUTING
  174. 2022-10-10 11:24:15.523533 40.07% [DEBUG] switch_ivr_originate.c:67 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_ROUTING -> CS_CONSUME_MEDIA
  175. 2022-10-10 11:24:15.523533 40.07% [DEBUG] switch_core_state_machine.c:640 (sofia/default/8485860527@142.132.184.134:5076) State ROUTING going to sleep
  176. 2022-10-10 11:24:15.523533 40.07% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_CONSUME_MEDIA (Cur 5 Tot 22254)
  177. 2022-10-10 11:24:15.523533 40.07% [DEBUG] switch_core_state_machine.c:659 (sofia/default/8485860527@142.132.184.134:5076) State CONSUME_MEDIA
  178. 2022-10-10 11:24:15.523533 40.07% [DEBUG] switch_core_state_machine.c:659 (sofia/default/8485860527@142.132.184.134:5076) State CONSUME_MEDIA going to sleep
  179. 2022-10-10 11:24:17.203531 42.03% [DEBUG] switch_ivr_originate.c:2281 Parsing global variables
  180. 2022-10-10 11:24:17.203531 42.03% [NOTICE] switch_channel.c:1123 New Channel sofia/default/8485860527@142.132.184.134:5076 [87b19504-6457-4e07-a9e9-51c8f8c797b6]
  181. 2022-10-10 11:24:17.203531 42.03% [DEBUG] mod_sofia.c:5121 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_NEW -> CS_INIT
  182. 2022-10-10 11:24:17.203531 42.03% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_INIT (Cur 6 Tot 22255)
  183. 2022-10-10 11:24:17.203531 42.03% [DEBUG] switch_core_state_machine.c:624 (sofia/default/8485860527@142.132.184.134:5076) State INIT
  184. 2022-10-10 11:24:17.203531 42.03% [DEBUG] mod_sofia.c:97 sofia/default/8485860527@142.132.184.134:5076 SOFIA INIT
  185. 2022-10-10 11:24:17.203531 42.03% [INFO] sofia_glue.c:1651 sofia/default/8485860527@142.132.184.134:5076 sending invite call-id: (null)
  186. 2022-10-10 11:24:17.203531 42.03% [DEBUG] sofia_glue.c:1654 sofia/default/8485860527@142.132.184.134:5076 sending invite version: 1.10.7 -release 64bit
  187. Local SDP:
  188. v=0
  189. o=FreeSWITCH 1665375815 1665375816 IN IP4 142.132.184.134
  190. s=FreeSWITCH
  191. c=IN IP4 142.132.184.134
  192. t=0 0
  193. m=audio 25242 RTP/AVP 8 0 101
  194. a=rtpmap:8 PCMA/8000
  195. a=rtpmap:0 PCMU/8000
  196. a=rtpmap:101 telephone-event/8000
  197. a=fmtp:101 0-15
  198. a=ptime:20
  199. a=sendrecv
  200.  
  201. 2022-10-10 11:24:17.203531 42.03% [DEBUG] switch_core_state_machine.c:40 sofia/default/8485860527@142.132.184.134:5076 Standard INIT
  202. 2022-10-10 11:24:17.203531 42.03% [DEBUG] switch_core_state_machine.c:48 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_INIT -> CS_ROUTING
  203. 2022-10-10 11:24:17.203531 42.03% [DEBUG] switch_core_state_machine.c:624 (sofia/default/8485860527@142.132.184.134:5076) State INIT going to sleep
  204. 2022-10-10 11:24:17.203531 42.03% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_ROUTING (Cur 6 Tot 22255)
  205. 2022-10-10 11:24:17.203531 42.03% [DEBUG] sofia.c:7499 Channel sofia/default/8485860527@142.132.184.134:5076 entering state [calling][0]
  206. 2022-10-10 11:24:17.203531 42.03% [DEBUG] switch_core_state_machine.c:640 (sofia/default/8485860527@142.132.184.134:5076) State ROUTING
  207. 2022-10-10 11:24:17.203531 42.03% [DEBUG] mod_sofia.c:158 sofia/default/8485860527@142.132.184.134:5076 SOFIA ROUTING
  208. 2022-10-10 11:24:17.203531 42.03% [DEBUG] switch_ivr_originate.c:67 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_ROUTING -> CS_CONSUME_MEDIA
  209. 2022-10-10 11:24:17.203531 42.03% [DEBUG] switch_core_state_machine.c:640 (sofia/default/8485860527@142.132.184.134:5076) State ROUTING going to sleep
  210. 2022-10-10 11:24:17.203531 42.03% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_CONSUME_MEDIA (Cur 6 Tot 22255)
  211. 2022-10-10 11:24:17.203531 42.03% [DEBUG] switch_core_state_machine.c:659 (sofia/default/8485860527@142.132.184.134:5076) State CONSUME_MEDIA
  212. 2022-10-10 11:24:17.203531 42.03% [DEBUG] switch_core_state_machine.c:659 (sofia/default/8485860527@142.132.184.134:5076) State CONSUME_MEDIA going to sleep
  213. 2022-10-10 11:24:18.903526 44.07% [DEBUG] switch_ivr_originate.c:2281 Parsing global variables
  214. 2022-10-10 11:24:18.903526 44.07% [NOTICE] switch_channel.c:1123 New Channel sofia/default/8485860527@142.132.184.134:5076 [73d15986-8d29-4c90-b63d-700de4b02a26]
  215. 2022-10-10 11:24:18.903526 44.07% [DEBUG] mod_sofia.c:5121 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_NEW -> CS_INIT
  216. 2022-10-10 11:24:18.903526 44.07% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_INIT (Cur 7 Tot 22256)
  217. 2022-10-10 11:24:18.903526 44.07% [DEBUG] switch_core_state_machine.c:624 (sofia/default/8485860527@142.132.184.134:5076) State INIT
  218. 2022-10-10 11:24:18.903526 44.07% [DEBUG] mod_sofia.c:97 sofia/default/8485860527@142.132.184.134:5076 SOFIA INIT
  219. 2022-10-10 11:24:18.903526 44.07% [INFO] sofia_glue.c:1651 sofia/default/8485860527@142.132.184.134:5076 sending invite call-id: (null)
  220. 2022-10-10 11:24:18.903526 44.07% [DEBUG] sofia_glue.c:1654 sofia/default/8485860527@142.132.184.134:5076 sending invite version: 1.10.7 -release 64bit
  221. Local SDP:
  222. v=0
  223. o=FreeSWITCH 1665373912 1665373913 IN IP4 142.132.184.134
  224. s=FreeSWITCH
  225. c=IN IP4 142.132.184.134
  226. t=0 0
  227. m=audio 27146 RTP/AVP 8 0 101
  228. a=rtpmap:8 PCMA/8000
  229. a=rtpmap:0 PCMU/8000
  230. a=rtpmap:101 telephone-event/8000
  231. a=fmtp:101 0-15
  232. a=ptime:20
  233. a=sendrecv
  234.  
  235. 2022-10-10 11:24:18.903526 44.07% [DEBUG] switch_core_state_machine.c:40 sofia/default/8485860527@142.132.184.134:5076 Standard INIT
  236. 2022-10-10 11:24:18.903526 44.07% [DEBUG] switch_core_state_machine.c:48 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_INIT -> CS_ROUTING
  237. 2022-10-10 11:24:18.903526 44.07% [DEBUG] switch_core_state_machine.c:624 (sofia/default/8485860527@142.132.184.134:5076) State INIT going to sleep
  238. 2022-10-10 11:24:18.903526 44.07% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_ROUTING (Cur 7 Tot 22256)
  239. 2022-10-10 11:24:18.903526 44.07% [DEBUG] sofia.c:7499 Channel sofia/default/8485860527@142.132.184.134:5076 entering state [calling][0]
  240. 2022-10-10 11:24:18.903526 44.07% [DEBUG] switch_core_state_machine.c:640 (sofia/default/8485860527@142.132.184.134:5076) State ROUTING
  241. 2022-10-10 11:24:18.903526 44.07% [DEBUG] mod_sofia.c:158 sofia/default/8485860527@142.132.184.134:5076 SOFIA ROUTING
  242. 2022-10-10 11:24:18.903526 44.07% [DEBUG] switch_ivr_originate.c:67 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_ROUTING -> CS_CONSUME_MEDIA
  243. 2022-10-10 11:24:18.903526 44.07% [DEBUG] switch_core_state_machine.c:640 (sofia/default/8485860527@142.132.184.134:5076) State ROUTING going to sleep
  244. 2022-10-10 11:24:18.903526 44.07% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_CONSUME_MEDIA (Cur 7 Tot 22256)
  245. 2022-10-10 11:24:18.903526 44.07% [DEBUG] switch_core_state_machine.c:659 (sofia/default/8485860527@142.132.184.134:5076) State CONSUME_MEDIA
  246. 2022-10-10 11:24:18.903526 44.07% [DEBUG] switch_core_state_machine.c:659 (sofia/default/8485860527@142.132.184.134:5076) State CONSUME_MEDIA going to sleep
  247. 2022-10-10 11:24:35.743535 54.50% [DEBUG] sofia.c:7499 Channel sofia/default/8485860527@142.132.184.134:5076 entering state [terminated][408]
  248. 2022-10-10 11:24:35.743535 54.50% [NOTICE] sofia.c:8738 Hangup sofia/default/8485860527@142.132.184.134:5076 [CS_CONSUME_MEDIA] [RECOVERY_ON_TIMER_EXPIRE]
  249. 2022-10-10 11:24:35.743535 54.50% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_HANGUP (Cur 7 Tot 22256)
  250. 2022-10-10 11:24:35.743535 54.50% [DEBUG] switch_core_state_machine.c:844 (sofia/default/8485860527@142.132.184.134:5076) Callstate Change DOWN -> HANGUP
  251. 2022-10-10 11:24:35.743535 54.50% [DEBUG] switch_core_state_machine.c:846 (sofia/default/8485860527@142.132.184.134:5076) State HANGUP
  252. 2022-10-10 11:24:35.743535 54.50% [DEBUG] mod_sofia.c:468 Channel sofia/default/8485860527@142.132.184.134:5076 hanging up, cause: RECOVERY_ON_TIMER_EXPIRE
  253. 2022-10-10 11:24:35.743535 54.50% [DEBUG] switch_core_state_machine.c:59 sofia/default/8485860527@142.132.184.134:5076 Standard HANGUP, cause: RECOVERY_ON_TIMER_EXPIRE
  254. 2022-10-10 11:24:35.743535 54.50% [DEBUG] switch_core_state_machine.c:846 (sofia/default/8485860527@142.132.184.134:5076) State HANGUP going to sleep
  255. 2022-10-10 11:24:35.743535 54.50% [DEBUG] switch_core_state_machine.c:616 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_HANGUP -> CS_REPORTING
  256. 2022-10-10 11:24:35.743535 54.50% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_REPORTING (Cur 7 Tot 22256)
  257. 2022-10-10 11:24:35.743535 54.50% [DEBUG] switch_core_state_machine.c:932 (sofia/default/8485860527@142.132.184.134:5076) State REPORTING
  258. 2022-10-10 11:24:35.743535 54.50% [INFO] mod_json_cdr.c:271 Process [9a26ab61-7191-472d-bb43-b3b615719f12.cdr.json]
  259. 2022-10-10 11:24:35.763537 54.50% [DEBUG] switch_ivr_originate.c:4035 Originate Resulted in Error Cause: 102 [RECOVERY_ON_TIMER_EXPIRE]
  260. 2022-10-10 11:24:35.763537 54.50% [DEBUG] switch_core_state_machine.c:168 sofia/default/8485860527@142.132.184.134:5076 Standard REPORTING, cause: RECOVERY_ON_TIMER_EXPIRE
  261. 2022-10-10 11:24:35.763537 54.50% [DEBUG] switch_core_state_machine.c:932 (sofia/default/8485860527@142.132.184.134:5076) State REPORTING going to sleep
  262. 2022-10-10 11:24:35.763537 54.50% [DEBUG] switch_core_state_machine.c:607 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_REPORTING -> CS_DESTROY
  263. 2022-10-10 11:24:35.763537 54.50% [DEBUG] switch_core_session.c:1753 Session 22250 (sofia/default/8485860527@142.132.184.134:5076) Locked, Waiting on external entities
  264. 2022-10-10 11:24:35.763537 54.50% [NOTICE] switch_core_session.c:1771 Session 22250 (sofia/default/8485860527@142.132.184.134:5076) Ended
  265. 2022-10-10 11:24:35.763537 54.50% [NOTICE] switch_core_session.c:1775 Close Channel sofia/default/8485860527@142.132.184.134:5076 [CS_DESTROY]
  266. 2022-10-10 11:24:35.763537 54.50% [DEBUG] switch_core_state_machine.c:735 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_DESTROY (Cur 6 Tot 22256)
  267. 2022-10-10 11:24:35.763537 54.50% [DEBUG] switch_core_state_machine.c:745 (sofia/default/8485860527@142.132.184.134:5076) State DESTROY
  268. 2022-10-10 11:24:35.763537 54.50% [DEBUG] mod_sofia.c:379 sofia/default/8485860527@142.132.184.134:5076 SOFIA DESTROY
  269. 2022-10-10 11:24:35.763537 54.50% [DEBUG] switch_core_state_machine.c:175 sofia/default/8485860527@142.132.184.134:5076 Standard DESTROY
  270. 2022-10-10 11:24:35.763537 54.50% [DEBUG] switch_core_state_machine.c:745 (sofia/default/8485860527@142.132.184.134:5076) State DESTROY going to sleep
  271. 2022-10-10 11:24:42.443531 54.63% [DEBUG] sofia.c:7499 Channel sofia/default/8485860527@142.132.184.134:5076 entering state [terminated][408]
  272. 2022-10-10 11:24:42.443531 54.63% [NOTICE] sofia.c:8738 Hangup sofia/default/8485860527@142.132.184.134:5076 [CS_CONSUME_MEDIA] [RECOVERY_ON_TIMER_EXPIRE]
  273. 2022-10-10 11:24:42.443531 54.63% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_HANGUP (Cur 6 Tot 22256)
  274. 2022-10-10 11:24:42.443531 54.63% [DEBUG] switch_core_state_machine.c:844 (sofia/default/8485860527@142.132.184.134:5076) Callstate Change DOWN -> HANGUP
  275. 2022-10-10 11:24:42.443531 54.63% [DEBUG] switch_core_state_machine.c:846 (sofia/default/8485860527@142.132.184.134:5076) State HANGUP
  276. 2022-10-10 11:24:42.443531 54.63% [DEBUG] mod_sofia.c:468 Channel sofia/default/8485860527@142.132.184.134:5076 hanging up, cause: RECOVERY_ON_TIMER_EXPIRE
  277. 2022-10-10 11:24:42.443531 54.63% [DEBUG] switch_core_state_machine.c:59 sofia/default/8485860527@142.132.184.134:5076 Standard HANGUP, cause: RECOVERY_ON_TIMER_EXPIRE
  278. 2022-10-10 11:24:42.443531 54.63% [DEBUG] switch_core_state_machine.c:846 (sofia/default/8485860527@142.132.184.134:5076) State HANGUP going to sleep
  279. 2022-10-10 11:24:42.443531 54.63% [DEBUG] switch_core_state_machine.c:616 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_HANGUP -> CS_REPORTING
  280. 2022-10-10 11:24:42.443531 54.63% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_REPORTING (Cur 6 Tot 22256)
  281. 2022-10-10 11:24:42.443531 54.63% [DEBUG] switch_core_state_machine.c:932 (sofia/default/8485860527@142.132.184.134:5076) State REPORTING
  282. 2022-10-10 11:24:42.443531 54.63% [INFO] mod_json_cdr.c:271 Process [8e7d0da0-a490-47fb-943a-27e64199136b.cdr.json]
  283. 2022-10-10 11:24:42.463532 54.63% [DEBUG] switch_core_state_machine.c:168 sofia/default/8485860527@142.132.184.134:5076 Standard REPORTING, cause: RECOVERY_ON_TIMER_EXPIRE
  284. 2022-10-10 11:24:42.463532 54.63% [DEBUG] switch_core_state_machine.c:932 (sofia/default/8485860527@142.132.184.134:5076) State REPORTING going to sleep
  285. 2022-10-10 11:24:42.463532 54.63% [DEBUG] switch_core_state_machine.c:607 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_REPORTING -> CS_DESTROY
  286. 2022-10-10 11:24:42.463532 54.63% [DEBUG] switch_core_session.c:1753 Session 22251 (sofia/default/8485860527@142.132.184.134:5076) Locked, Waiting on external entities
  287. 2022-10-10 11:24:42.463532 54.63% [DEBUG] switch_ivr_originate.c:4035 Originate Resulted in Error Cause: 102 [RECOVERY_ON_TIMER_EXPIRE]
  288. 2022-10-10 11:24:42.463532 54.63% [NOTICE] switch_core_session.c:1771 Session 22251 (sofia/default/8485860527@142.132.184.134:5076) Ended
  289. 2022-10-10 11:24:42.463532 54.63% [NOTICE] switch_core_session.c:1775 Close Channel sofia/default/8485860527@142.132.184.134:5076 [CS_DESTROY]
  290. 2022-10-10 11:24:42.463532 54.63% [DEBUG] switch_core_state_machine.c:735 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_DESTROY (Cur 5 Tot 22256)
  291. 2022-10-10 11:24:42.463532 54.63% [DEBUG] switch_core_state_machine.c:745 (sofia/default/8485860527@142.132.184.134:5076) State DESTROY
  292. 2022-10-10 11:24:42.463532 54.63% [DEBUG] mod_sofia.c:379 sofia/default/8485860527@142.132.184.134:5076 SOFIA DESTROY
  293. 2022-10-10 11:24:42.463532 54.63% [DEBUG] switch_core_state_machine.c:175 sofia/default/8485860527@142.132.184.134:5076 Standard DESTROY
  294. 2022-10-10 11:24:42.463532 54.63% [DEBUG] switch_core_state_machine.c:745 (sofia/default/8485860527@142.132.184.134:5076) State DESTROY going to sleep
  295. 2022-10-10 11:24:43.143535 54.57% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [900400@astppqa605.astppbilling.org] from ip 103.240.35.46
  296. 2022-10-10 11:24:44.143532 54.53% [DEBUG] sofia.c:7499 Channel sofia/default/8485860527@142.132.184.134:5076 entering state [terminated][408]
  297. 2022-10-10 11:24:44.143532 54.53% [NOTICE] sofia.c:8738 Hangup sofia/default/8485860527@142.132.184.134:5076 [CS_CONSUME_MEDIA] [RECOVERY_ON_TIMER_EXPIRE]
  298. 2022-10-10 11:24:44.143532 54.53% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_HANGUP (Cur 5 Tot 22256)
  299. 2022-10-10 11:24:44.143532 54.53% [DEBUG] switch_core_state_machine.c:844 (sofia/default/8485860527@142.132.184.134:5076) Callstate Change DOWN -> HANGUP
  300. 2022-10-10 11:24:44.143532 54.53% [DEBUG] switch_core_state_machine.c:846 (sofia/default/8485860527@142.132.184.134:5076) State HANGUP
  301. 2022-10-10 11:24:44.143532 54.53% [DEBUG] mod_sofia.c:468 Channel sofia/default/8485860527@142.132.184.134:5076 hanging up, cause: RECOVERY_ON_TIMER_EXPIRE
  302. 2022-10-10 11:24:44.143532 54.53% [DEBUG] switch_core_state_machine.c:59 sofia/default/8485860527@142.132.184.134:5076 Standard HANGUP, cause: RECOVERY_ON_TIMER_EXPIRE
  303. 2022-10-10 11:24:44.143532 54.53% [DEBUG] switch_core_state_machine.c:846 (sofia/default/8485860527@142.132.184.134:5076) State HANGUP going to sleep
  304. 2022-10-10 11:24:44.143532 54.53% [DEBUG] switch_core_state_machine.c:616 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_HANGUP -> CS_REPORTING
  305. 2022-10-10 11:24:44.143532 54.53% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_REPORTING (Cur 5 Tot 22256)
  306. 2022-10-10 11:24:44.143532 54.53% [DEBUG] switch_core_state_machine.c:932 (sofia/default/8485860527@142.132.184.134:5076) State REPORTING
  307. 2022-10-10 11:24:44.143532 54.53% [INFO] mod_json_cdr.c:271 Process [79c2c4d2-92ef-4d38-9904-89727ac551d3.cdr.json]
  308. 2022-10-10 11:24:44.143532 54.53% [DEBUG] switch_ivr_originate.c:4035 Originate Resulted in Error Cause: 102 [RECOVERY_ON_TIMER_EXPIRE]
  309. 2022-10-10 11:24:44.143532 54.53% [DEBUG] switch_core_state_machine.c:168 sofia/default/8485860527@142.132.184.134:5076 Standard REPORTING, cause: RECOVERY_ON_TIMER_EXPIRE
  310. 2022-10-10 11:24:44.143532 54.53% [DEBUG] switch_core_state_machine.c:932 (sofia/default/8485860527@142.132.184.134:5076) State REPORTING going to sleep
  311. 2022-10-10 11:24:44.143532 54.53% [DEBUG] switch_core_state_machine.c:607 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_REPORTING -> CS_DESTROY
  312. 2022-10-10 11:24:44.143532 54.53% [DEBUG] switch_core_session.c:1753 Session 22252 (sofia/default/8485860527@142.132.184.134:5076) Locked, Waiting on external entities
  313. 2022-10-10 11:24:44.143532 54.53% [NOTICE] switch_core_session.c:1771 Session 22252 (sofia/default/8485860527@142.132.184.134:5076) Ended
  314. 2022-10-10 11:24:44.143532 54.53% [NOTICE] switch_core_session.c:1775 Close Channel sofia/default/8485860527@142.132.184.134:5076 [CS_DESTROY]
  315. 2022-10-10 11:24:44.143532 54.53% [DEBUG] switch_core_state_machine.c:735 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_DESTROY (Cur 4 Tot 22256)
  316. 2022-10-10 11:24:44.143532 54.53% [DEBUG] switch_core_state_machine.c:745 (sofia/default/8485860527@142.132.184.134:5076) State DESTROY
  317. 2022-10-10 11:24:44.143532 54.53% [DEBUG] mod_sofia.c:379 sofia/default/8485860527@142.132.184.134:5076 SOFIA DESTROY
  318. 2022-10-10 11:24:44.143532 54.53% [DEBUG] switch_core_state_machine.c:175 sofia/default/8485860527@142.132.184.134:5076 Standard DESTROY
  319. 2022-10-10 11:24:44.143532 54.53% [DEBUG] switch_core_state_machine.c:745 (sofia/default/8485860527@142.132.184.134:5076) State DESTROY going to sleep
  320. 2022-10-10 11:24:45.843532 54.50% [DEBUG] sofia.c:7499 Channel sofia/default/8485860527@142.132.184.134:5076 entering state [terminated][408]
  321. 2022-10-10 11:24:45.843532 54.50% [NOTICE] sofia.c:8738 Hangup sofia/default/8485860527@142.132.184.134:5076 [CS_CONSUME_MEDIA] [RECOVERY_ON_TIMER_EXPIRE]
  322. 2022-10-10 11:24:45.843532 54.50% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_HANGUP (Cur 4 Tot 22256)
  323. 2022-10-10 11:24:45.843532 54.50% [DEBUG] switch_core_state_machine.c:844 (sofia/default/8485860527@142.132.184.134:5076) Callstate Change DOWN -> HANGUP
  324. 2022-10-10 11:24:45.843532 54.50% [DEBUG] switch_core_state_machine.c:846 (sofia/default/8485860527@142.132.184.134:5076) State HANGUP
  325. 2022-10-10 11:24:45.843532 54.50% [DEBUG] mod_sofia.c:468 Channel sofia/default/8485860527@142.132.184.134:5076 hanging up, cause: RECOVERY_ON_TIMER_EXPIRE
  326. 2022-10-10 11:24:45.843532 54.50% [DEBUG] switch_core_state_machine.c:59 sofia/default/8485860527@142.132.184.134:5076 Standard HANGUP, cause: RECOVERY_ON_TIMER_EXPIRE
  327. 2022-10-10 11:24:45.843532 54.50% [DEBUG] switch_core_state_machine.c:846 (sofia/default/8485860527@142.132.184.134:5076) State HANGUP going to sleep
  328. 2022-10-10 11:24:45.843532 54.50% [DEBUG] switch_core_state_machine.c:616 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_HANGUP -> CS_REPORTING
  329. 2022-10-10 11:24:45.843532 54.50% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_REPORTING (Cur 4 Tot 22256)
  330. 2022-10-10 11:24:45.843532 54.50% [DEBUG] switch_core_state_machine.c:932 (sofia/default/8485860527@142.132.184.134:5076) State REPORTING
  331. 2022-10-10 11:24:45.843532 54.50% [INFO] mod_json_cdr.c:271 Process [4ff12a14-ca02-4472-ae06-c069d4defc20.cdr.json]
  332. 2022-10-10 11:24:45.843532 54.50% [DEBUG] switch_core_state_machine.c:168 sofia/default/8485860527@142.132.184.134:5076 Standard REPORTING, cause: RECOVERY_ON_TIMER_EXPIRE
  333. 2022-10-10 11:24:45.843532 54.50% [DEBUG] switch_core_state_machine.c:932 (sofia/default/8485860527@142.132.184.134:5076) State REPORTING going to sleep
  334. 2022-10-10 11:24:45.843532 54.50% [DEBUG] switch_core_state_machine.c:607 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_REPORTING -> CS_DESTROY
  335. 2022-10-10 11:24:45.843532 54.50% [DEBUG] switch_core_session.c:1753 Session 22253 (sofia/default/8485860527@142.132.184.134:5076) Locked, Waiting on external entities
  336. 2022-10-10 11:24:45.843532 54.50% [DEBUG] switch_ivr_originate.c:4035 Originate Resulted in Error Cause: 102 [RECOVERY_ON_TIMER_EXPIRE]
  337. 2022-10-10 11:24:45.843532 54.50% [NOTICE] switch_core_session.c:1771 Session 22253 (sofia/default/8485860527@142.132.184.134:5076) Ended
  338. 2022-10-10 11:24:45.843532 54.50% [NOTICE] switch_core_session.c:1775 Close Channel sofia/default/8485860527@142.132.184.134:5076 [CS_DESTROY]
  339. 2022-10-10 11:24:45.843532 54.50% [DEBUG] switch_core_state_machine.c:735 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_DESTROY (Cur 3 Tot 22256)
  340. 2022-10-10 11:24:45.843532 54.50% [DEBUG] switch_core_state_machine.c:745 (sofia/default/8485860527@142.132.184.134:5076) State DESTROY
  341. 2022-10-10 11:24:45.843532 54.50% [DEBUG] mod_sofia.c:379 sofia/default/8485860527@142.132.184.134:5076 SOFIA DESTROY
  342. 2022-10-10 11:24:45.843532 54.50% [DEBUG] switch_core_state_machine.c:175 sofia/default/8485860527@142.132.184.134:5076 Standard DESTROY
  343. 2022-10-10 11:24:45.843532 54.50% [DEBUG] switch_core_state_machine.c:745 (sofia/default/8485860527@142.132.184.134:5076) State DESTROY going to sleep
  344. 2022-10-10 11:24:47.523547 54.50% [DEBUG] sofia.c:7499 Channel sofia/default/8485860527@142.132.184.134:5076 entering state [terminated][408]
  345. 2022-10-10 11:24:47.523547 54.50% [NOTICE] sofia.c:8738 Hangup sofia/default/8485860527@142.132.184.134:5076 [CS_CONSUME_MEDIA] [RECOVERY_ON_TIMER_EXPIRE]
  346. 2022-10-10 11:24:47.523547 54.50% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_HANGUP (Cur 3 Tot 22256)
  347. 2022-10-10 11:24:47.523547 54.50% [DEBUG] switch_core_state_machine.c:844 (sofia/default/8485860527@142.132.184.134:5076) Callstate Change DOWN -> HANGUP
  348. 2022-10-10 11:24:47.523547 54.50% [DEBUG] switch_core_state_machine.c:846 (sofia/default/8485860527@142.132.184.134:5076) State HANGUP
  349. 2022-10-10 11:24:47.523547 54.50% [DEBUG] mod_sofia.c:468 Channel sofia/default/8485860527@142.132.184.134:5076 hanging up, cause: RECOVERY_ON_TIMER_EXPIRE
  350. 2022-10-10 11:24:47.523547 54.50% [DEBUG] switch_core_state_machine.c:59 sofia/default/8485860527@142.132.184.134:5076 Standard HANGUP, cause: RECOVERY_ON_TIMER_EXPIRE
  351. 2022-10-10 11:24:47.523547 54.50% [DEBUG] switch_core_state_machine.c:846 (sofia/default/8485860527@142.132.184.134:5076) State HANGUP going to sleep
  352. 2022-10-10 11:24:47.523547 54.50% [DEBUG] switch_core_state_machine.c:616 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_HANGUP -> CS_REPORTING
  353. 2022-10-10 11:24:47.523547 54.50% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_REPORTING (Cur 3 Tot 22256)
  354. 2022-10-10 11:24:47.523547 54.50% [DEBUG] switch_core_state_machine.c:932 (sofia/default/8485860527@142.132.184.134:5076) State REPORTING
  355. 2022-10-10 11:24:47.523547 54.50% [INFO] mod_json_cdr.c:271 Process [e1839fcd-f9ad-483b-bee1-33af86bc0726.cdr.json]
  356. 2022-10-10 11:24:47.523547 54.50% [DEBUG] switch_core_state_machine.c:168 sofia/default/8485860527@142.132.184.134:5076 Standard REPORTING, cause: RECOVERY_ON_TIMER_EXPIRE
  357. 2022-10-10 11:24:47.523547 54.50% [DEBUG] switch_core_state_machine.c:932 (sofia/default/8485860527@142.132.184.134:5076) State REPORTING going to sleep
  358. 2022-10-10 11:24:47.523547 54.50% [DEBUG] switch_core_state_machine.c:607 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_REPORTING -> CS_DESTROY
  359. 2022-10-10 11:24:47.523547 54.50% [DEBUG] switch_core_session.c:1753 Session 22254 (sofia/default/8485860527@142.132.184.134:5076) Locked, Waiting on external entities
  360. 2022-10-10 11:24:47.543533 54.50% [DEBUG] switch_ivr_originate.c:4035 Originate Resulted in Error Cause: 102 [RECOVERY_ON_TIMER_EXPIRE]
  361. 2022-10-10 11:24:47.543533 54.50% [NOTICE] switch_core_session.c:1771 Session 22254 (sofia/default/8485860527@142.132.184.134:5076) Ended
  362. 2022-10-10 11:24:47.543533 54.50% [NOTICE] switch_core_session.c:1775 Close Channel sofia/default/8485860527@142.132.184.134:5076 [CS_DESTROY]
  363. 2022-10-10 11:24:47.543533 54.50% [DEBUG] switch_core_state_machine.c:735 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_DESTROY (Cur 2 Tot 22256)
  364. 2022-10-10 11:24:47.543533 54.50% [DEBUG] switch_core_state_machine.c:745 (sofia/default/8485860527@142.132.184.134:5076) State DESTROY
  365. 2022-10-10 11:24:47.543533 54.50% [DEBUG] mod_sofia.c:379 sofia/default/8485860527@142.132.184.134:5076 SOFIA DESTROY
  366. 2022-10-10 11:24:47.543533 54.50% [DEBUG] switch_core_state_machine.c:175 sofia/default/8485860527@142.132.184.134:5076 Standard DESTROY
  367. 2022-10-10 11:24:47.543533 54.50% [DEBUG] switch_core_state_machine.c:745 (sofia/default/8485860527@142.132.184.134:5076) State DESTROY going to sleep
  368. 2022-10-10 11:24:49.203534 54.40% [DEBUG] sofia.c:7499 Channel sofia/default/8485860527@142.132.184.134:5076 entering state [terminated][408]
  369. 2022-10-10 11:24:49.203534 54.40% [NOTICE] sofia.c:8738 Hangup sofia/default/8485860527@142.132.184.134:5076 [CS_CONSUME_MEDIA] [RECOVERY_ON_TIMER_EXPIRE]
  370. 2022-10-10 11:24:49.203534 54.40% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_HANGUP (Cur 2 Tot 22256)
  371. 2022-10-10 11:24:49.203534 54.40% [DEBUG] switch_core_state_machine.c:844 (sofia/default/8485860527@142.132.184.134:5076) Callstate Change DOWN -> HANGUP
  372. 2022-10-10 11:24:49.203534 54.40% [DEBUG] switch_core_state_machine.c:846 (sofia/default/8485860527@142.132.184.134:5076) State HANGUP
  373. 2022-10-10 11:24:49.203534 54.40% [DEBUG] mod_sofia.c:468 Channel sofia/default/8485860527@142.132.184.134:5076 hanging up, cause: RECOVERY_ON_TIMER_EXPIRE
  374. 2022-10-10 11:24:49.203534 54.40% [DEBUG] switch_core_state_machine.c:59 sofia/default/8485860527@142.132.184.134:5076 Standard HANGUP, cause: RECOVERY_ON_TIMER_EXPIRE
  375. 2022-10-10 11:24:49.203534 54.40% [DEBUG] switch_core_state_machine.c:846 (sofia/default/8485860527@142.132.184.134:5076) State HANGUP going to sleep
  376. 2022-10-10 11:24:49.203534 54.40% [DEBUG] switch_core_state_machine.c:616 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_HANGUP -> CS_REPORTING
  377. 2022-10-10 11:24:49.203534 54.40% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_REPORTING (Cur 2 Tot 22256)
  378. 2022-10-10 11:24:49.203534 54.40% [DEBUG] switch_core_state_machine.c:932 (sofia/default/8485860527@142.132.184.134:5076) State REPORTING
  379. 2022-10-10 11:24:49.203534 54.40% [INFO] mod_json_cdr.c:271 Process [87b19504-6457-4e07-a9e9-51c8f8c797b6.cdr.json]
  380. 2022-10-10 11:24:49.203534 54.40% [DEBUG] switch_core_state_machine.c:168 sofia/default/8485860527@142.132.184.134:5076 Standard REPORTING, cause: RECOVERY_ON_TIMER_EXPIRE
  381. 2022-10-10 11:24:49.203534 54.40% [DEBUG] switch_core_state_machine.c:932 (sofia/default/8485860527@142.132.184.134:5076) State REPORTING going to sleep
  382. 2022-10-10 11:24:49.203534 54.40% [DEBUG] switch_core_state_machine.c:607 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_REPORTING -> CS_DESTROY
  383. 2022-10-10 11:24:49.203534 54.40% [DEBUG] switch_core_session.c:1753 Session 22255 (sofia/default/8485860527@142.132.184.134:5076) Locked, Waiting on external entities
  384. 2022-10-10 11:24:49.223524 54.40% [DEBUG] switch_ivr_originate.c:4035 Originate Resulted in Error Cause: 102 [RECOVERY_ON_TIMER_EXPIRE]
  385. 2022-10-10 11:24:49.223524 54.40% [NOTICE] switch_core_session.c:1771 Session 22255 (sofia/default/8485860527@142.132.184.134:5076) Ended
  386. 2022-10-10 11:24:49.223524 54.40% [NOTICE] switch_core_session.c:1775 Close Channel sofia/default/8485860527@142.132.184.134:5076 [CS_DESTROY]
  387. 2022-10-10 11:24:49.223524 54.40% [DEBUG] switch_core_state_machine.c:735 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_DESTROY (Cur 1 Tot 22256)
  388. 2022-10-10 11:24:49.223524 54.40% [DEBUG] switch_core_state_machine.c:745 (sofia/default/8485860527@142.132.184.134:5076) State DESTROY
  389. 2022-10-10 11:24:49.223524 54.40% [DEBUG] mod_sofia.c:379 sofia/default/8485860527@142.132.184.134:5076 SOFIA DESTROY
  390. 2022-10-10 11:24:49.223524 54.40% [DEBUG] switch_core_state_machine.c:175 sofia/default/8485860527@142.132.184.134:5076 Standard DESTROY
  391. 2022-10-10 11:24:49.223524 54.40% [DEBUG] switch_core_state_machine.c:745 (sofia/default/8485860527@142.132.184.134:5076) State DESTROY going to sleep
  392. 2022-10-10 11:24:50.903539 54.47% [DEBUG] sofia.c:7499 Channel sofia/default/8485860527@142.132.184.134:5076 entering state [terminated][408]
  393. 2022-10-10 11:24:50.903539 54.47% [NOTICE] sofia.c:8738 Hangup sofia/default/8485860527@142.132.184.134:5076 [CS_CONSUME_MEDIA] [RECOVERY_ON_TIMER_EXPIRE]
  394. 2022-10-10 11:24:50.903539 54.47% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_HANGUP (Cur 1 Tot 22256)
  395. 2022-10-10 11:24:50.903539 54.47% [DEBUG] switch_core_state_machine.c:844 (sofia/default/8485860527@142.132.184.134:5076) Callstate Change DOWN -> HANGUP
  396. 2022-10-10 11:24:50.903539 54.47% [DEBUG] switch_core_state_machine.c:846 (sofia/default/8485860527@142.132.184.134:5076) State HANGUP
  397. 2022-10-10 11:24:50.903539 54.47% [DEBUG] mod_sofia.c:468 Channel sofia/default/8485860527@142.132.184.134:5076 hanging up, cause: RECOVERY_ON_TIMER_EXPIRE
  398. 2022-10-10 11:24:50.903539 54.47% [DEBUG] switch_core_state_machine.c:59 sofia/default/8485860527@142.132.184.134:5076 Standard HANGUP, cause: RECOVERY_ON_TIMER_EXPIRE
  399. 2022-10-10 11:24:50.903539 54.47% [DEBUG] switch_core_state_machine.c:846 (sofia/default/8485860527@142.132.184.134:5076) State HANGUP going to sleep
  400. 2022-10-10 11:24:50.903539 54.47% [DEBUG] switch_core_state_machine.c:616 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_HANGUP -> CS_REPORTING
  401. 2022-10-10 11:24:50.903539 54.47% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_REPORTING (Cur 1 Tot 22256)
  402. 2022-10-10 11:24:50.903539 54.47% [DEBUG] switch_core_state_machine.c:932 (sofia/default/8485860527@142.132.184.134:5076) State REPORTING
  403. 2022-10-10 11:24:50.923549 54.47% [INFO] mod_json_cdr.c:271 Process [73d15986-8d29-4c90-b63d-700de4b02a26.cdr.json]
  404. 2022-10-10 11:24:50.923549 54.47% [DEBUG] switch_core_state_machine.c:168 sofia/default/8485860527@142.132.184.134:5076 Standard REPORTING, cause: RECOVERY_ON_TIMER_EXPIRE
  405. 2022-10-10 11:24:50.923549 54.47% [DEBUG] switch_core_state_machine.c:932 (sofia/default/8485860527@142.132.184.134:5076) State REPORTING going to sleep
  406. 2022-10-10 11:24:50.923549 54.47% [DEBUG] switch_core_state_machine.c:607 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_REPORTING -> CS_DESTROY
  407. 2022-10-10 11:24:50.923549 54.47% [DEBUG] switch_core_session.c:1753 Session 22256 (sofia/default/8485860527@142.132.184.134:5076) Locked, Waiting on external entities
  408. 2022-10-10 11:24:50.923549 54.47% [DEBUG] switch_ivr_originate.c:4035 Originate Resulted in Error Cause: 102 [RECOVERY_ON_TIMER_EXPIRE]
  409. 2022-10-10 11:24:50.923549 54.47% [NOTICE] switch_core_session.c:1771 Session 22256 (sofia/default/8485860527@142.132.184.134:5076) Ended
  410. 2022-10-10 11:24:50.923549 54.47% [NOTICE] switch_core_session.c:1775 Close Channel sofia/default/8485860527@142.132.184.134:5076 [CS_DESTROY]
  411. 2022-10-10 11:24:50.923549 54.47% [DEBUG] switch_core_state_machine.c:735 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_DESTROY (Cur 0 Tot 22256)
  412. 2022-10-10 11:24:50.923549 54.47% [DEBUG] switch_core_state_machine.c:745 (sofia/default/8485860527@142.132.184.134:5076) State DESTROY
  413. 2022-10-10 11:24:50.923549 54.47% [DEBUG] mod_sofia.c:379 sofia/default/8485860527@142.132.184.134:5076 SOFIA DESTROY
  414. 2022-10-10 11:24:50.923549 54.47% [DEBUG] switch_core_state_machine.c:175 sofia/default/8485860527@142.132.184.134:5076 Standard DESTROY
  415. 2022-10-10 11:24:50.923549 54.47% [DEBUG] switch_core_state_machine.c:745 (sofia/default/8485860527@142.132.184.134:5076) State DESTROY going to sleep
  416. 2022-10-10 11:24:55.803535 55.10% [WARNING] sofia_reg.c:1861 SIP auth challenge (INVITE) on sofia profile 'default' for [4727985745@astppqa601.astppbilling.org] from ip 103.240.35.46