From Naseer, 3 Years ago, written in FreeSWITCH.
- view diff
Embed
  1. span style="color: cornflowerblue; font-weight: bold;"> 2020-07-09 21:16:47.771541 [NOTICE] switch_channel.c:1118 New Channel sofia/internal/718291782@43.225.1.1 [bf481e37-12bd-4a87-a12c-cbcf7ffb5212]
  2. 2020-07-09 21:16:47.771541 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/718291782@43.225.1.1) Running State Change CS_NEW (Cur 1 Tot 1)
  3. 2020-07-09 21:16:47.771541 [DEBUG] sofia.c:10279 sofia/internal/718291782@43.225.1.1 receiving invite from 43.225.1.1:5060 version: 1.10.4-dev git 00113c4 2020-06-29 18:46:18Z 64bit
  4. 2020-07-09 21:16:47.771541 [DEBUG] sofia.c:10373 verifying acl "domains" for ip/port 43.225.1.1:0.
  5. 2020-07-09 21:16:47.771541 [DEBUG] sofia.c:10402 IP 43.225.1.1 Approved by acl "domains[]". Access Granted.
  6. 2020-07-09 21:16:47.791476 [DEBUG] sofia.c:7325 Channel sofia/internal/718291782@43.225.1.1 entering state [received][100]
  7. 2020-07-09 21:16:47.791476 [DEBUG] sofia.c:7335 Remote SDP:
  8. v=0
  9. o=- 77028 77028 IN IP4 192.1.1.1
  10. s=-
  11. c=IN IP4 43.225.1.1
  12. t=0 0
  13. m=audio 48346 RTP/AVP 0
  14. a=rtpmap:0 PCMU/8000
  15. a=ptime:40
  16. m=image 46286 udptl t38
  17. a=T38FaxVersion:0
  18. a=T38MaxBitRate:14400
  19. a=T38FaxUdpEC:t38UDPRedundancy
  20. a=T38FaxRateManagement:transferredTCF
  21. a=T38FaxFillBitRemoval:0
  22. a=T38FaxTranscodingMMR:0
  23. a=T38FaxTranscodingJBIG:0
  24. a=direction:active
  25.  
  26. 2020-07-09 21:16:47.791476 [DEBUG] sofia.c:7738 (sofia/internal/718291782@43.225.1.1) State Change CS_NEW -> CS_INIT
  27. 2020-07-09 21:16:47.791476 [DEBUG] switch_core_state_machine.c:604 (sofia/internal/718291782@43.225.1.1) State NEW
  28. 2020-07-09 21:16:47.791476 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/718291782@43.225.1.1) Running State Change CS_INIT (Cur 1 Tot 1)
  29. 2020-07-09 21:16:47.791476 [DEBUG] switch_core_state_machine.c:628 (sofia/internal/718291782@43.225.1.1) State INIT
  30. 2020-07-09 21:16:47.791476 [DEBUG] mod_sofia.c:93 sofia/internal/718291782@43.225.1.1 SOFIA INIT
  31. 2020-07-09 21:16:47.791476 [DEBUG] switch_core_state_machine.c:40 sofia/internal/718291782@43.225.1.1 Standard INIT
  32. 2020-07-09 21:16:47.791476 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/718291782@43.225.1.1) State Change CS_INIT -> CS_ROUTING
  33. 2020-07-09 21:16:47.791476 [DEBUG] switch_core_state_machine.c:628 (sofia/internal/718291782@43.225.1.1) State INIT going to sleep
  34. 2020-07-09 21:16:47.791476 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/718291782@43.225.1.1) Running State Change CS_ROUTING (Cur 1 Tot 1)
  35. 2020-07-09 21:16:47.791476 [DEBUG] switch_channel.c:2332 (sofia/internal/718291782@43.225.1.1) Callstate Change DOWN -> RINGING
  36. 2020-07-09 21:16:47.791476 [DEBUG] switch_core_state_machine.c:644 (sofia/internal/718291782@43.225.1.1) State ROUTING
  37. 2020-07-09 21:16:47.791476 [DEBUG] mod_sofia.c:154 sofia/internal/718291782@43.225.1.1 SOFIA ROUTING
  38. 2020-07-09 21:16:47.791476 [DEBUG] switch_core_state_machine.c:236 sofia/internal/718291782@43.225.1.1 Standard ROUTING
  39. 2020-07-09 21:16:47.791476 [INFO] mod_dialplan_xml.c:637 Processing 718291782 <718291782>->73715050001110 in context public
  40. Dialplan: sofia/internal/718291782@43.225.1.1 parsing [public->unloop] continue=false
  41. Dialplan: sofia/internal/718291782@43.225.1.1 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
  42. Dialplan: sofia/internal/718291782@43.225.1.1 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
  43. Dialplan: sofia/internal/718291782@43.225.1.1 parsing [public->outside_call] continue=true
  44. Dialplan: sofia/internal/718291782@43.225.1.1 Absolute Condition [outside_call]
  45. Dialplan: sofia/internal/718291782@43.225.1.1 Action set(outside_call=true)
  46. Dialplan: sofia/internal/718291782@43.225.1.1 Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
  47. Dialplan: sofia/internal/718291782@43.225.1.1 parsing [public->call_debug] continue=true
  48. Dialplan: sofia/internal/718291782@43.225.1.1 Regex (FAIL) [call_debug] ${call_debug}(false) =~ /^true$/ break=never
  49. Dialplan: sofia/internal/718291782@43.225.1.1 parsing [public->public_extensions] continue=false
  50. Dialplan: sofia/internal/718291782@43.225.1.1 Regex (FAIL) [public_extensions] destination_number(73715050001110) =~ /^(10[01][0-9])$/ break=on-false
  51. Dialplan: sofia/internal/718291782@43.225.1.1 parsing [public->public_conference_extensions] continue=false
  52. Dialplan: sofia/internal/718291782@43.225.1.1 Regex (FAIL) [public_conference_extensions] destination_number(73715050001110) =~ /^(3[5-8][01][0-9])$/ break=on-false
  53. Dialplan: sofia/internal/718291782@43.225.1.1 parsing [public->local-delay-echo] continue=false
  54. Dialplan: sofia/internal/718291782@43.225.1.1 Regex (PASS) [local-delay-echo] destination_number(73715050001110) =~ /^73715050001110$/ break=on-false
  55. Dialplan: sofia/internal/718291782@43.225.1.1 Action answer()
  56. Dialplan: sofia/internal/718291782@43.225.1.1 Action delay_echo(5000)
  57. 2020-07-09 21:16:47.791476 [DEBUG] switch_core_state_machine.c:287 (sofia/internal/718291782@43.225.1.1) State Change CS_ROUTING -> CS_EXECUTE
  58. 2020-07-09 21:16:47.791476 [DEBUG] switch_core_state_machine.c:644 (sofia/internal/718291782@43.225.1.1) State ROUTING going to sleep
  59. 2020-07-09 21:16:47.791476 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/718291782@43.225.1.1) Running State Change CS_EXECUTE (Cur 1 Tot 1)
  60. 2020-07-09 21:16:47.791476 [DEBUG] switch_core_state_machine.c:651 (sofia/internal/718291782@43.225.1.1) State EXECUTE
  61. 2020-07-09 21:16:47.791476 [DEBUG] mod_sofia.c:209 sofia/internal/718291782@43.225.1.1 SOFIA EXECUTE
  62. 2020-07-09 21:16:47.791476 [DEBUG] switch_core_state_machine.c:329 sofia/internal/718291782@43.225.1.1 Standard EXECUTE
  63. EXECUTE [depth=0] sofia/internal/718291782@43.225.1.1 set(outside_call=true)
  64. 2020-07-09 21:16:47.791476 [CONSOLE] sofia_presence.c:1619 Event Thread Started
  65. 2020-07-09 21:16:47.791476 [DEBUG] mod_dptools.c:1672 SET sofia/internal/718291782@43.225.1.1 [outside_call]=[true]
  66. EXECUTE [depth=0] sofia/internal/718291782@43.225.1.1 export(RFC2822_DATE=Thu, 09 Jul 2020 21:16:47 +0500)
  67. 2020-07-09 21:16:47.791476 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [RFC2822_DATE]=[Thu, 09 Jul 2020 21:16:47 +0500]
  68. EXECUTE [depth=0] sofia/internal/718291782@43.225.1.1 answer()
  69. 2020-07-09 21:16:47.791476 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMU:0:8000:40:64000:1]/[G722:9:8000:20:64000:1]
  70. 2020-07-09 21:16:47.791476 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMU:0:8000:40:64000:1]/[PCMU:0:8000:20:64000:1]
  71. 2020-07-09 21:16:47.791476 [DEBUG] switch_core_media.c:5630 Audio Codec Compare [PCMU:0:8000:20:64000:1] is saved as a near-match
  72. 2020-07-09 21:16:47.791476 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMU:0:8000:40:64000:1]/[PCMA:8:8000:20:64000:1]
  73. 2020-07-09 21:16:47.791476 [DEBUG] switch_core_media.c:5701 Substituting codec PCMU@40i@8000h@1c
  74. 2020-07-09 21:16:47.791476 [DEBUG] switch_core_media.c:3839 Set Codec sofia/internal/718291782@43.225.1.1 PCMU/8000 40 ms 320 samples 64000 bits 1 channels
  75. 2020-07-09 21:16:47.791476 [DEBUG] switch_core_codec.c:111 sofia/internal/718291782@43.225.1.1 Original read codec set to PCMU:0
  76. 2020-07-09 21:16:47.791476 [DEBUG] switch_core_media.c:5882 No 2833 in SDP. Liberal DTMF mode adding 101 as telephone-event.
  77. 2020-07-09 21:16:47.791476 [DEBUG] switch_core_media.c:5911 sofia/internal/718291782@43.225.1.1 Set 2833 dtmf send payload to 101 recv payload to 101
  78. 2020-07-09 21:16:47.791476 [DEBUG] switch_core_media.c:5172 sofia/internal/718291782@43.225.1.1 T38 REFUSE on request
  79. 2020-07-09 21:16:47.791476 [DEBUG] switch_core_media.c:8663 AUDIO RTP [sofia/internal/718291782@43.225.1.1] 43.225.1.2 port 25500 -> 43.225.1.1 port 48346 codec: 0 ms: 40
  80. 2020-07-09 21:16:47.791476 [DEBUG] switch_rtp.c:4431 Starting timer [soft] 320 bytes per 40ms
  81. 2020-07-09 21:16:47.791476 [DEBUG] switch_core_media.c:8977 sofia/internal/718291782@43.225.1.1 Set 2833 dtmf send payload to 101
  82. 2020-07-09 21:16:47.791476 [DEBUG] switch_core_media.c:8984 sofia/internal/718291782@43.225.1.1 Set 2833 dtmf receive payload to 101
  83. 2020-07-09 21:16:47.791476 [DEBUG] switch_core_media.c:9007 sofia/internal/718291782@43.225.1.1 Set rtp dtmf delay to 40
  84. 2020-07-09 21:16:47.791476 [NOTICE] sofia_media.c:92 Pre-Answer sofia/internal/718291782@43.225.1.1!
  85. 2020-07-09 21:16:47.791476 [DEBUG] switch_channel.c:3565 (sofia/internal/718291782@43.225.1.1) Callstate Change RINGING -> EARLY
  86. 2020-07-09 21:16:47.791476 [DEBUG] switch_core_media.c:8645 Audio params are unchanged for sofia/internal/718291782@43.225.1.1.
  87. 2020-07-09 21:16:47.791476 [DEBUG] mod_sofia.c:898 Local SDP sofia/internal/718291782@43.225.1.1:
  88. v=0
  89. o=FreeSWITCH 1594285907 1594285908 IN IP4 43.225.1.2
  90. s=FreeSWITCH
  91. c=IN IP4 43.225.1.2
  92. t=0 0
  93. m=audio 25500 RTP/AVP 0 101
  94. a=rtpmap:0 PCMU/8000
  95. a=rtpmap:101 telephone-event/8000
  96. a=fmtp:101 0-16
  97. a=ptime:40
  98. a=sendrecv
  99. m=image 0 UDPTL T38
  100.  
  101. 2020-07-09 21:16:47.791476 [NOTICE] mod_dptools.c:1406 Channel [sofia/internal/718291782@43.225.1.1] has been answered
  102. 2020-07-09 21:16:47.791476 [DEBUG] switch_channel.c:3865 (sofia/internal/718291782@43.225.1.1) Callstate Change EARLY -> ACTIVE
  103. 2020-07-09 21:16:47.791476 [DEBUG] sofia.c:7325 Channel sofia/internal/718291782@43.225.1.1 entering state [completed][200]
  104. EXECUTE [depth=0] sofia/internal/718291782@43.225.1.1 delay_echo(5000)
  105. 2020-07-09 21:16:47.791476 [DEBUG] switch_ivr.c:3552 Setting delay to 5000ms (125 frames)
  106. 2020-07-09 21:16:47.851575 [DEBUG] sofia.c:7325 Channel sofia/internal/718291782@43.225.1.1 entering state [ready][200]
  107. freeswitch@ylinx-redtone-LIBOX>
  108. 2020-07-09 21:17:41.511554 [NOTICE] sofia.c:1089 Hangup sofia/internal/718291782@43.225.1.1 [CS_EXECUTE] [NORMAL_CLEARING]
  109. 2020-07-09 21:17:41.511554 [DEBUG] switch_core_session.c:2905 sofia/internal/718291782@43.225.1.1 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
  110. 2020-07-09 21:17:41.511554 [DEBUG] switch_core_state_machine.c:651 (sofia/internal/718291782@43.225.1.1) State EXECUTE going to sleep
  111. 2020-07-09 21:17:41.511554 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/718291782@43.225.1.1) Running State Change CS_HANGUP (Cur 1 Tot 1)
  112. 2020-07-09 21:17:41.511554 [DEBUG] switch_core_state_machine.c:848 (sofia/internal/718291782@43.225.1.1) Callstate Change ACTIVE -> HANGUP
  113. 2020-07-09 21:17:41.511554 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/718291782@43.225.1.1) State HANGUP
  114. 2020-07-09 21:17:41.511554 [DEBUG] mod_sofia.c:453 Channel sofia/internal/718291782@43.225.1.1 hanging up, cause: NORMAL_CLEARING
  115. 2020-07-09 21:17:41.511554 [DEBUG] switch_core_state_machine.c:60 sofia/internal/718291782@43.225.1.1 Standard HANGUP, cause: NORMAL_CLEARING
  116. 2020-07-09 21:17:41.511554 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/718291782@43.225.1.1) State HANGUP going to sleep
  117. 2020-07-09 21:17:41.511554 [DEBUG] switch_core_state_machine.c:620 (sofia/internal/718291782@43.225.1.1) State Change CS_HANGUP -> CS_REPORTING
  118. 2020-07-09 21:17:41.511554 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/718291782@43.225.1.1) Running State Change CS_REPORTING (Cur 1 Tot 1)
  119. 2020-07-09 21:17:41.511554 [DEBUG] switch_core_state_machine.c:936 (sofia/internal/718291782@43.225.1.1) State REPORTING
  120. 2020-07-09 21:17:41.511554 [DEBUG] switch_core_state_machine.c:174 sofia/internal/718291782@43.225.1.1 Standard REPORTING, cause: NORMAL_CLEARING
  121. 2020-07-09 21:17:41.511554 [DEBUG] switch_core_state_machine.c:936 (sofia/internal/718291782@43.225.1.1) State REPORTING going to sleep
  122. 2020-07-09 21:17:41.511554 [DEBUG] switch_core_state_machine.c:611 (sofia/internal/718291782@43.225.1.1) State Change CS_REPORTING -> CS_DESTROY
  123. 2020-07-09 21:17:41.511554 [DEBUG] switch_core_session.c:1726 Session 1 (sofia/internal/718291782@43.225.1.1) Locked, Waiting on external entities
  124. 2020-07-09 21:17:41.511554 [NOTICE] switch_core_session.c:1744 Session 1 (sofia/internal/718291782@43.225.1.1) Ended
  125. 2020-07-09 21:17:41.511554 [NOTICE] switch_core_session.c:1748 Close Channel sofia/internal/718291782@43.225.1.1 [CS_DESTROY]
  126. 2020-07-09 21:17:41.511554 [DEBUG] switch_core_state_machine.c:739 (sofia/internal/718291782@43.225.1.1) Running State Change CS_DESTROY (Cur 0 Tot 1)
  127. 2020-07-09 21:17:41.511554 [DEBUG] switch_core_state_machine.c:749 (sofia/internal/718291782@43.225.1.1) State DESTROY
  128. 2020-07-09 21:17:41.511554 [DEBUG] mod_sofia.c:364 sofia/internal/718291782@43.225.1.1 SOFIA DESTROY
  129. 2020-07-09 21:17:41.511554 [DEBUG] switch_core_state_machine.c:181 sofia/internal/718291782@43.225.1.1 Standard DESTROY
  130. 2020-07-09 21:17:41.511554 [DEBUG] switch_core_state_machine.c:749 (sofia/internal/718291782@43.225.1.1) State DESTROY going to sleep