From xbipin, 7 Years ago, written in FreeSWITCH.
- go back
Embed
Viewing differences between and Untitled
  1. login as: pi
  2. pi@bsnl.myn2p.com's password:
  3.  
  4. The programs included with the Debian GNU/Linux system are free software;
  5. the exact distribution terms for each program are described in the
  6.  
  7. +OK log level  [7]
  8. 2016-06-15 13:04:44.329977 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/21@192.168.30.36 [a112ccda-32cb-11e6-b33c-811a74d51aac]
  9. 2016-06-15 13:04:44.329977 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/21@192.168.30.36) Running State Change CS_NEW
  10. 2016-06-15 13:04:44.349998 [DEBUG] sofia.c:9402 sofia/internal/21@192.168.30.36 receiving invite from 192.168.30.64:61782 version: 1.7.0 git 9d7fe24 2016-06-06 15:09:02Z 32bit
  11. 2016-06-15 13:04:44.349998 [DEBUG] sofia.c:9514 IP 192.168.30.64 Approved by acl "domains[]". Access Granted.
  12. 2016-06-15 13:04:44.349998 [DEBUG] sofia.c:6883 Channel sofia/internal/21@192.168.30.36 entering state [received][100]
  13. 2016-06-15 13:04:44.349998 [DEBUG] sofia.c:6893 Remote SDP:
  14. v=0
  15. o=Zoiper 0 0 IN IP4 192.168.30.64
  16. s=Zoiper
  17. c=IN IP4 192.168.30.64
  18. t=0 0
  19. m=audio 33646 RTP/AVP 106 18 0 101
  20. a=rtpmap:106 opus/48000/2
  21. a=fmtp:106 maxplaybackrate=16000; sprop-maxcapturerate=16000; minptime=20; cbr=1; maxaveragebitrate=20000; useinbandfec=1
  22. a=rtpmap:18 G729/8000
  23. a=fmtp:18 annexb=no
  24. a=rtpmap:0 PCMU/8000
  25. a=rtpmap:101 telephone-event/8000
  26. a=fmtp:101 0-16
  27.  
  28. 2016-06-15 13:04:44.349998 [DEBUG] sofia.c:7253 (sofia/internal/21@192.168.30.36) State Change CS_NEW -> CS_INIT
  29. 2016-06-15 13:04:44.349998 [DEBUG] switch_core_state_machine.c:562 (sofia/internal/21@192.168.30.36) State NEW
  30. 2016-06-15 13:04:44.349998 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/21@192.168.30.36) Running State Change CS_INIT
  31. 2016-06-15 13:04:44.349998 [DEBUG] switch_core_state_machine.c:586 (sofia/internal/21@192.168.30.36) State INIT
  32. 2016-06-15 13:04:44.349998 [DEBUG] mod_sofia.c:89 sofia/internal/21@192.168.30.36 SOFIA INIT
  33. 2016-06-15 13:04:44.349998 [DEBUG] switch_core_state_machine.c:40 sofia/internal/21@192.168.30.36 Standard INIT
  34. 2016-06-15 13:04:44.349998 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/21@192.168.30.36) State Change CS_INIT -> CS_ROUTING
  35. 2016-06-15 13:04:44.349998 [DEBUG] switch_core_state_machine.c:586 (sofia/internal/21@192.168.30.36) State INIT going to sleep
  36. 2016-06-15 13:04:44.349998 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/21@192.168.30.36) Running State Change CS_ROUTING
  37. 2016-06-15 13:04:44.349998 [DEBUG] switch_channel.c:2249 (sofia/internal/21@192.168.30.36) Callstate Change DOWN -> RINGING
  38. 2016-06-15 13:04:44.349998 [DEBUG] switch_core_state_machine.c:602 (sofia/internal/21@192.168.30.36) State ROUTING
  39. 2016-06-15 13:04:44.349998 [DEBUG] mod_sofia.c:142 sofia/internal/21@192.168.30.36 SOFIA ROUTING
  40. 2016-06-15 13:04:44.349998 [DEBUG] switch_core_state_machine.c:236 sofia/internal/21@192.168.30.36 Standard ROUTING
  41. 2016-06-15 13:04:44.349998 [INFO] mod_dialplan_xml.c:637 Processing Mufaddal <21>->29 in context lanusersdialout
  42. Dialplan: sofia/internal/21@192.168.30.36 parsing [lanusersdialout->unloop] continue=false
  43. Dialplan: sofia/internal/21@192.168.30.36 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
  44. Dialplan: sofia/internal/21@192.168.30.36 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
  45. Dialplan: sofia/internal/21@192.168.30.36 parsing [lanusersdialout->general_stuff1] continue=true
  46. Dialplan: sofia/internal/21@192.168.30.36 Absolute Condition [general_stuff1]
  47. Dialplan: sofia/internal/21@192.168.30.36 Action set(rtp_negotiate_near_match=true)
  48. Dialplan: sofia/internal/21@192.168.30.36 Action set(inherit_codec=true)
  49. Dialplan: sofia/internal/21@192.168.30.36 Action set(suppress_cng=true)
  50. Dialplan: sofia/internal/21@192.168.30.36 parsing [lanusersdialout->3g_inbound] continue=false
  51. Dialplan: sofia/internal/21@192.168.30.36 Regex (FAIL) [3g_inbound] destination_number(29) =~ /^9997$/ break=on-false
  52. Dialplan: sofia/internal/21@192.168.30.36 parsing [lanusersdialout->myn2p_outbound] continue=false
  53. Dialplan: sofia/internal/21@192.168.30.36 Regex (FAIL) [myn2p_outbound] destination_number(29) =~ /^(00.*)$/ break=on-false
  54. Dialplan: sofia/internal/21@192.168.30.36 parsing [lanusersdialout->3g_outbound4] continue=false
  55. Dialplan: sofia/internal/21@192.168.30.36 Regex (FAIL) [3g_outbound4] destination_number(29) =~ /^0(1.*)$/ break=on-false
  56. Dialplan: sofia/internal/21@192.168.30.36 parsing [lanusersdialout->3g_outbound5] continue=false
  57. Dialplan: sofia/internal/21@192.168.30.36 Regex (FAIL) [3g_outbound5] destination_number(29) =~ /^\+91(.*)$/ break=on-false
  58. Dialplan: sofia/internal/21@192.168.30.36 parsing [lanusersdialout->3g_outbound] continue=false
  59. Dialplan: sofia/internal/21@192.168.30.36 Regex (FAIL) [3g_outbound] destination_number(29) =~ /^(0.*)$/ break=on-false
  60. Dialplan: sofia/internal/21@192.168.30.36 parsing [lanusersdialout->group_dial_support] continue=false
  61. Dialplan: sofia/internal/21@192.168.30.36 Regex (FAIL) [group_dial_support] destination_number(29) =~ /^2001$/ break=on-false
  62. Dialplan: sofia/internal/21@192.168.30.36 parsing [lanusersdialout->local_user_calling] continue=false
  63. Dialplan: sofia/internal/21@192.168.30.36 Regex (PASS) [local_user_calling] destination_number(29) =~ /^(.*)$/ break=on-false
  64. Dialplan: sofia/internal/21@192.168.30.36 Action bind_meta_app(3 b s execute_extension::att_xfer XML features)
  65. Dialplan: sofia/internal/21@192.168.30.36 Action set(transfer_ringback=local_stream://moh)
  66. Dialplan: sofia/internal/21@192.168.30.36 Action set(call_timeout=30)
  67. Dialplan: sofia/internal/21@192.168.30.36 Action set(hangup_after_bridge=true)
  68. Dialplan: sofia/internal/21@192.168.30.36 Action bridge(sofia/internal/29%${domain})
  69. 2016-06-15 13:04:44.349998 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/21@192.168.30.36) State Change CS_ROUTING -> CS_EXECUTE
  70. 2016-06-15 13:04:44.349998 [DEBUG] switch_core_state_machine.c:602 (sofia/internal/21@192.168.30.36) State ROUTING going to sleep
  71. 2016-06-15 13:04:44.349998 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/21@192.168.30.36) Running State Change CS_EXECUTE
  72. 2016-06-15 13:04:44.349998 [DEBUG] switch_core_state_machine.c:609 (sofia/internal/21@192.168.30.36) State EXECUTE
  73. 2016-06-15 13:04:44.349998 [DEBUG] mod_sofia.c:197 sofia/internal/21@192.168.30.36 SOFIA EXECUTE
  74. 2016-06-15 13:04:44.349998 [DEBUG] switch_core_state_machine.c:328 sofia/internal/21@192.168.30.36 Standard EXECUTE
  75. EXECUTE sofia/internal/21@192.168.30.36 set(rtp_negotiate_near_match=true)
  76. 2016-06-15 13:04:44.349998 [DEBUG] mod_dptools.c:1519 SET sofia/internal/21@192.168.30.36 [rtp_negotiate_near_match]=[true]
  77. EXECUTE sofia/internal/21@192.168.30.36 set(inherit_codec=true)
  78. 2016-06-15 13:04:44.349998 [DEBUG] mod_dptools.c:1519 SET sofia/internal/21@192.168.30.36 [inherit_codec]=[true]
  79. EXECUTE sofia/internal/21@192.168.30.36 set(suppress_cng=true)
  80. 2016-06-15 13:04:44.349998 [DEBUG] mod_dptools.c:1519 SET sofia/internal/21@192.168.30.36 [suppress_cng]=[true]
  81. EXECUTE sofia/internal/21@192.168.30.36 bind_meta_app(3 b s execute_extension::att_xfer XML features)
  82. 2016-06-15 13:04:44.349998 [INFO] switch_ivr_async.c:4166 Bound B-Leg: *3 execute_extension::att_xfer XML features
  83. EXECUTE sofia/internal/21@192.168.30.36 set(transfer_ringback=local_stream://moh)
  84. 2016-06-15 13:04:44.349998 [DEBUG] mod_dptools.c:1519 SET sofia/internal/21@192.168.30.36 [transfer_ringback]=[local_stream://moh]
  85. EXECUTE sofia/internal/21@192.168.30.36 set(call_timeout=30)
  86. 2016-06-15 13:04:44.349998 [DEBUG] mod_dptools.c:1519 SET sofia/internal/21@192.168.30.36 [call_timeout]=[30]
  87. EXECUTE sofia/internal/21@192.168.30.36 set(hangup_after_bridge=true)
  88. 2016-06-15 13:04:44.349998 [DEBUG] mod_dptools.c:1519 SET sofia/internal/21@192.168.30.36 [hangup_after_bridge]=[true]
  89. EXECUTE sofia/internal/21@192.168.30.36 bridge(sofia/internal/29%192.168.30.36)
  90. 2016-06-15 13:04:44.349998 [DEBUG] switch_ivr_originate.c:2127 Parsing global variables
  91. 2016-06-15 13:04:44.349998 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/29 [a115aa18-32cb-11e6-b348-811a74d51aac]
  92. 2016-06-15 13:04:44.349998 [DEBUG] mod_sofia.c:4816 (sofia/internal/29) State Change CS_NEW -> CS_INIT
  93. 2016-06-15 13:04:44.369992 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/29) Running State Change CS_INIT
  94. 2016-06-15 13:04:44.369992 [DEBUG] switch_core_state_machine.c:586 (sofia/internal/29) State INIT
  95. 2016-06-15 13:04:44.369992 [DEBUG] mod_sofia.c:89 sofia/internal/29 SOFIA INIT
  96. 2016-06-15 13:04:44.369992 [DEBUG] switch_core_port_allocator.c:183 UDP port robustness check for port 1028 pass
  97. 2016-06-15 13:04:44.369992 [DEBUG] sofia_glue.c:1257 sofia/internal/29 sending invite version: 1.7.0 git 9d7fe24 2016-06-06 15:09:02Z 32bit
  98. Local SDP:
  99. v=0
  100. o=Talkycom 1465975056 1465975057 IN IP4 192.168.30.36
  101. s=Talkycom
  102. c=IN IP4 192.168.30.36
  103. t=0 0
  104. m=audio 1028 RTP/AVP 102 18 0 103 101
  105. a=rtpmap:102 opus/48000/2
  106. a=fmtp:102 useinbandfec=1; usedtx=1; cbr=1; maxaveragebitrate=20000; maxplaybackrate=16000; sprop-maxcapturerate=16000; ptime=20; minptime=10; maxptime=40; stereo=1
  107. a=rtpmap:18 G729/8000
  108. a=rtpmap:0 PCMU/8000
  109. a=rtpmap:103 telephone-event/48000
  110. a=fmtp:103 0-16
  111. a=rtpmap:101 telephone-event/8000
  112. a=fmtp:101 0-16
  113. a=silenceSupp:off - - - -
  114. a=ptime:20
  115. a=sendrecv
  116.  
  117. 2016-06-15 13:04:44.369992 [DEBUG] switch_core_state_machine.c:40 sofia/internal/29 Standard INIT
  118. 2016-06-15 13:04:44.369992 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/29) State Change CS_INIT -> CS_ROUTING
  119. 2016-06-15 13:04:44.369992 [DEBUG] switch_core_state_machine.c:586 (sofia/internal/29) State INIT going to sleep
  120. 2016-06-15 13:04:44.369992 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/29) Running State Change CS_ROUTING
  121. 2016-06-15 13:04:44.369992 [DEBUG] sofia.c:6883 Channel sofia/internal/29 entering state [calling][0]
  122. 2016-06-15 13:04:44.369992 [DEBUG] switch_core_state_machine.c:602 (sofia/internal/29) State ROUTING
  123. 2016-06-15 13:04:44.369992 [DEBUG] mod_sofia.c:142 sofia/internal/29 SOFIA ROUTING
  124. 2016-06-15 13:04:44.369992 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/29) State Change CS_ROUTING -> CS_CONSUME_MEDIA
  125. 2016-06-15 13:04:44.369992 [DEBUG] switch_core_state_machine.c:602 (sofia/internal/29) State ROUTING going to sleep
  126. 2016-06-15 13:04:44.369992 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/29) Running State Change CS_CONSUME_MEDIA
  127. 2016-06-15 13:04:44.369992 [DEBUG] switch_core_state_machine.c:621 (sofia/internal/29) State CONSUME_MEDIA
  128. 2016-06-15 13:04:44.369992 [DEBUG] switch_core_state_machine.c:621 (sofia/internal/29) State CONSUME_MEDIA going to sleep
  129. 2016-06-15 13:04:44.549980 [DEBUG] sofia.c:6883 Channel sofia/internal/29 entering state [proceeding][180]
  130. 2016-06-15 13:04:44.549980 [NOTICE] sofia.c:6986 Ring-Ready sofia/internal/29!
  131. 2016-06-15 13:04:44.549980 [DEBUG] switch_channel.c:3343 (sofia/internal/29) Callstate Change DOWN -> RINGING
  132. 2016-06-15 13:04:44.569979 [NOTICE] mod_sofia.c:2201 Ring-Ready sofia/internal/21@192.168.30.36!
  133. 2016-06-15 13:04:44.569979 [DEBUG] sofia.c:6883 Channel sofia/internal/21@192.168.30.36 entering state [early][180]
  134. 2016-06-15 13:04:44.569979 [NOTICE] switch_ivr_originate.c:525 Ring Ready sofia/internal/21@192.168.30.36!
  135. 2016-06-15 13:04:47.369977 [DEBUG] sofia.c:6883 Channel sofia/internal/29 entering state [completing][200]
  136. 2016-06-15 13:04:47.369977 [DEBUG] sofia.c:6893 Remote SDP:
  137. v=0
  138. o=Zoiper 0 1 IN IP4 192.168.30.171
  139. s=Zoiper
  140. c=IN IP4 192.168.30.171
  141. t=0 0
  142. m=audio 44524 RTP/AVP 106 18 0 101
  143. a=rtpmap:106 opus/48000/2
  144. a=fmtp:106 maxplaybackrate=16000; sprop-maxcapturerate=16000; minptime=20; cbr=1; maxaveragebitrate=20000; useinbandfec=1
  145. a=rtpmap:18 G729/8000
  146. a=fmtp:18 annexb=no
  147. a=rtpmap:0 PCMU/8000
  148. a=rtpmap:101 telephone-event/8000
  149. a=fmtp:101 0-16
  150.  
  151. 2016-06-15 13:04:47.369977 [DEBUG] sofia.c:6883 Channel sofia/internal/29 entering state [ready][200]
  152. 2016-06-15 13:04:47.369977 [DEBUG] switch_core_media.c:4365 Audio Codec Compare [opus:106:48000:20:0:1]/[opus:116:48000:20:0:2]
  153. 2016-06-15 13:04:47.369977 [DEBUG] switch_core_media.c:4420 Audio Codec Compare [opus:116:48000:20:0:2] ++++ is saved as a match
  154. 2016-06-15 13:04:47.369977 [DEBUG] switch_core_media.c:4365 Audio Codec Compare [opus:106:48000:20:0:1]/[G729:18:8000:20:8000:1]
  155. 2016-06-15 13:04:47.369977 [DEBUG] switch_core_media.c:4365 Audio Codec Compare [opus:106:48000:20:0:1]/[PCMU:0:8000:20:64000:1]
  156. 2016-06-15 13:04:47.369977 [DEBUG] switch_core_media.c:4365 Audio Codec Compare [G729:18:8000:20:8000:1]/[opus:116:48000:20:0:2]
  157. 2016-06-15 13:04:47.369977 [DEBUG] switch_core_media.c:4365 Audio Codec Compare [G729:18:8000:20:8000:1]/[G729:18:8000:20:8000:1]
  158. 2016-06-15 13:04:47.369977 [DEBUG] switch_core_media.c:4420 Audio Codec Compare [G729:18:8000:20:8000:1] ++++ is saved as a match
  159. 2016-06-15 13:04:47.369977 [DEBUG] switch_core_media.c:4365 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
  160. 2016-06-15 13:04:47.369977 [DEBUG] switch_core_media.c:4365 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:2]
  161. 2016-06-15 13:04:47.369977 [DEBUG] switch_core_media.c:4365 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G729:18:8000:20:8000:1]
  162. 2016-06-15 13:04:47.369977 [DEBUG] switch_core_media.c:4365 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  163. 2016-06-15 13:04:47.369977 [DEBUG] switch_core_media.c:4420 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
  164. 2016-06-15 13:04:47.369977 [DEBUG] switch_core_media.c:4281 Set telephone-event payload to 101@8000
  165. 2016-06-15 13:04:47.369977 [DEBUG] mod_opus.c:554 Opus encoder: set bitrate based on maxaveragebitrate value found in SDP or local config [20000bps]
  166. 2016-06-15 13:04:47.369977 [DEBUG] mod_opus.c:571 Opus encoder: set audio bandwidth to [WIDEBAND] based on maxplaybackrate value found in SDP or local config [16000Hz]
  167. 2016-06-15 13:04:47.369977 [DEBUG] mod_opus.c:578 Opus encoder: CBR mode enabled
  168. 2016-06-15 13:04:47.369977 [DEBUG] mod_opus.c:554 Opus encoder: set bitrate based on maxaveragebitrate value found in SDP or local config [20000bps]
  169. 2016-06-15 13:04:47.369977 [DEBUG] mod_opus.c:571 Opus encoder: set audio bandwidth to [WIDEBAND] based on maxplaybackrate value found in SDP or local config [16000Hz]
  170. 2016-06-15 13:04:47.369977 [DEBUG] mod_opus.c:578 Opus encoder: CBR mode enabled
  171. 2016-06-15 13:04:47.369977 [DEBUG] switch_core_media.c:3091 Set Codec sofia/internal/29 opus/48000 20 ms 960 samples 0 bits 1 channels
  172. 2016-06-15 13:04:47.369977 [DEBUG] switch_core_codec.c:111 sofia/internal/29 Original read codec set to opus:116
  173. 2016-06-15 13:04:47.369977 [DEBUG] switch_core_media.c:4692 sofia/internal/29 Set 2833 dtmf send payload to 101 recv payload to 101
  174. 2016-06-15 13:04:47.369977 [DEBUG] switch_core_media.c:6495 AUDIO RTP [sofia/internal/29] 192.168.30.36 port 1028 -> 192.168.30.171 port 44524 codec: 106 ms: 20
  175. 2016-06-15 13:04:47.369977 [DEBUG] switch_rtp.c:3832 Starting timer [soft] 960 bytes per 20ms
  176. 2016-06-15 13:04:47.369977 [DEBUG] switch_core_media.c:6794 sofia/internal/29 Set 2833 dtmf send payload to 101
  177. 2016-06-15 13:04:47.369977 [DEBUG] switch_core_media.c:6801 sofia/internal/29 Set 2833 dtmf receive payload to 101
  178. 2016-06-15 13:04:47.369977 [DEBUG] switch_core_media.c:6824 sofia/internal/29 Set rtp dtmf delay to 40
  179. 2016-06-15 13:04:47.389984 [NOTICE] sofia.c:7852 Channel [sofia/internal/29] has been answered
  180. 2016-06-15 13:04:47.389984 [DEBUG] switch_channel.c:3770 (sofia/internal/29) Callstate Change RINGING -> ACTIVE
  181. 2016-06-15 13:04:47.389984 [DEBUG] switch_ivr_originate.c:410 Setting codec string on sofia/internal/21@192.168.30.36 to opus@48000h@20i
  182. 2016-06-15 13:04:47.389984 [DEBUG] switch_core_media.c:4365 Audio Codec Compare [opus:106:48000:20:0:1]/[opus:116:48000:20:0:1]
  183. 2016-06-15 13:04:47.389984 [DEBUG] switch_core_media.c:4420 Audio Codec Compare [opus:116:48000:20:0:1] ++++ is saved as a match
  184. 2016-06-15 13:04:47.389984 [DEBUG] switch_core_media.c:4365 Audio Codec Compare [G729:18:8000:20:8000:1]/[opus:116:48000:20:0:1]
  185. 2016-06-15 13:04:47.389984 [DEBUG] switch_core_media.c:4365 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1]
  186. 2016-06-15 13:04:47.389984 [DEBUG] switch_core_media.c:4281 Set telephone-event payload to 101@8000
  187. 2016-06-15 13:04:47.389984 [DEBUG] mod_opus.c:554 Opus encoder: set bitrate based on maxaveragebitrate value found in SDP or local config [20000bps]
  188. 2016-06-15 13:04:47.389984 [DEBUG] mod_opus.c:571 Opus encoder: set audio bandwidth to [WIDEBAND] based on maxplaybackrate value found in SDP or local config [16000Hz]
  189. 2016-06-15 13:04:47.389984 [DEBUG] mod_opus.c:578 Opus encoder: CBR mode enabled
  190. 2016-06-15 13:04:47.389984 [DEBUG] mod_opus.c:554 Opus encoder: set bitrate based on maxaveragebitrate value found in SDP or local config [20000bps]
  191. 2016-06-15 13:04:47.389984 [DEBUG] mod_opus.c:571 Opus encoder: set audio bandwidth to [WIDEBAND] based on maxplaybackrate value found in SDP or local config [16000Hz]
  192. 2016-06-15 13:04:47.389984 [DEBUG] mod_opus.c:578 Opus encoder: CBR mode enabled
  193. 2016-06-15 13:04:47.389984 [DEBUG] switch_core_media.c:3091 Set Codec sofia/internal/21@192.168.30.36 opus/48000 20 ms 960 samples 0 bits 1 channels
  194. 2016-06-15 13:04:47.389984 [DEBUG] switch_core_codec.c:111 sofia/internal/21@192.168.30.36 Original read codec set to opus:116
  195. 2016-06-15 13:04:47.389984 [DEBUG] switch_core_media.c:4692 sofia/internal/21@192.168.30.36 Set 2833 dtmf send payload to 101 recv payload to 101
  196. 2016-06-15 13:04:47.389984 [DEBUG] switch_core_port_allocator.c:183 UDP port robustness check for port 1026 pass
  197. 2016-06-15 13:04:47.389984 [DEBUG] switch_core_media.c:6495 AUDIO RTP [sofia/internal/21@192.168.30.36] 192.168.30.36 port 1026 -> 192.168.30.64 port 33646 codec: 106 ms: 20
  198. 2016-06-15 13:04:47.389984 [DEBUG] switch_rtp.c:3832 Starting timer [soft] 960 bytes per 20ms
  199. 2016-06-15 13:04:47.389984 [DEBUG] switch_core_media.c:6794 sofia/internal/21@192.168.30.36 Set 2833 dtmf send payload to 101
  200. 2016-06-15 13:04:47.389984 [DEBUG] switch_core_media.c:6801 sofia/internal/21@192.168.30.36 Set 2833 dtmf receive payload to 101
  201. 2016-06-15 13:04:47.389984 [DEBUG] switch_core_media.c:6824 sofia/internal/21@192.168.30.36 Set rtp dtmf delay to 40
  202. 2016-06-15 13:04:47.389984 [NOTICE] sofia_media.c:92 Pre-Answer sofia/internal/21@192.168.30.36!
  203. 2016-06-15 13:04:47.409994 [DEBUG] switch_channel.c:3471 (sofia/internal/21@192.168.30.36) Callstate Change RINGING -> EARLY
  204. 2016-06-15 13:04:47.409994 [DEBUG] mod_sofia.c:816 Local SDP sofia/internal/21@192.168.30.36:
  205. v=0
  206. o=Talkycom 1465975061 1465975062 IN IP4 192.168.30.36
  207. s=Talkycom
  208. c=IN IP4 192.168.30.36
  209. t=0 0
  210. m=audio 1026 RTP/AVP 106 101
  211. a=rtpmap:106 opus/48000/2
  212. a=fmtp:106 useinbandfec=1; usedtx=1; cbr=1; maxaveragebitrate=20000; maxplaybackrate=16000; sprop-maxcapturerate=16000; minptime=20
  213. a=rtpmap:101 telephone-event/8000
  214. a=fmtp:101 0-16
  215. a=silenceSupp:off - - - -
  216. a=ptime:20
  217. a=sendrecv
  218.  
  219. 2016-06-15 13:04:47.409994 [NOTICE] switch_ivr_originate.c:3549 Channel [sofia/internal/21@192.168.30.36] has been answered
  220. 2016-06-15 13:04:47.409994 [DEBUG] switch_channel.c:3770 (sofia/internal/21@192.168.30.36) Callstate Change EARLY -> ACTIVE
  221. 2016-06-15 13:04:47.409994 [DEBUG] sofia.c:6883 Channel sofia/internal/21@192.168.30.36 entering state [completed][200]
  222. 2016-06-15 13:04:47.409994 [DEBUG] switch_ivr_originate.c:3607 Originate Resulted in Success: [sofia/internal/29]
  223. 2016-06-15 13:04:47.409994 [DEBUG] switch_ivr_bridge.c:1594 (sofia/internal/29) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
  224. 2016-06-15 13:04:47.409994 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/29) Running State Change CS_EXCHANGE_MEDIA
  225. 2016-06-15 13:04:47.409994 [DEBUG] switch_core_state_machine.c:612 (sofia/internal/29) State EXCHANGE_MEDIA
  226. 2016-06-15 13:04:47.409994 [DEBUG] mod_sofia.c:630 SOFIA EXCHANGE_MEDIA
  227. 2016-06-15 13:04:47.469979 [DEBUG] sofia.c:6883 Channel sofia/internal/21@192.168.30.36 entering state [ready][200]
  228. 2016-06-15 13:04:47.749979 [DEBUG] switch_rtp.c:6707 Correct audio ip/port confirmed.
  229. 2016-06-15 13:04:58.509979 [NOTICE] sofia_reg.c:448 Registering myn2p
  230. 2016-06-15 13:04:58.729981 [DEBUG] sofia_reg.c:2429 Changing expire time to 240 by request of proxy sip:72.55.165.151
  231. 2016-06-15 13:05:24.389980 [NOTICE] sofia.c:988 Hangup sofia/internal/21@192.168.30.36 [CS_EXECUTE] [NORMAL_CLEARING]
  232. 2016-06-15 13:05:24.389980 [DEBUG] switch_ivr_bridge.c:780 BRIDGE THREAD DONE [sofia/internal/21@192.168.30.36]
  233. 2016-06-15 13:05:24.389980 [DEBUG] switch_ivr_bridge.c:780 BRIDGE THREAD DONE [sofia/internal/29]
  234. 2016-06-15 13:05:24.389980 [NOTICE] switch_ivr_bridge.c:884 Hangup sofia/internal/29 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING]
  235. 2016-06-15 13:05:24.389980 [DEBUG] switch_core_state_machine.c:612 (sofia/internal/29) State EXCHANGE_MEDIA going to sleep
  236. 2016-06-15 13:05:24.389980 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/29) Running State Change CS_HANGUP
  237. 2016-06-15 13:05:24.409995 [DEBUG] switch_core_state_machine.c:809 (sofia/internal/29) Callstate Change ACTIVE -> HANGUP
  238. 2016-06-15 13:05:24.409995 [DEBUG] switch_ivr_bridge.c:1692 sofia/internal/29 skip receive message [UNBRIDGE] (channel is hungup already)
  239. 2016-06-15 13:05:24.409995 [DEBUG] switch_ivr_bridge.c:1695 sofia/internal/21@192.168.30.36 skip receive message [UNBRIDGE] (channel is hungup already)
  240. 2016-06-15 13:05:24.409995 [DEBUG] switch_core_state_machine.c:811 (sofia/internal/29) State HANGUP
  241. 2016-06-15 13:05:24.409995 [DEBUG] mod_sofia.c:431 sofia/internal/29 Overriding SIP cause 480 with 200 from the other leg
  242. 2016-06-15 13:05:24.409995 [DEBUG] mod_sofia.c:437 Channel sofia/internal/29 hanging up, cause: NORMAL_CLEARING
  243. 2016-06-15 13:05:24.409995 [DEBUG] mod_sofia.c:490 Sending BYE to sofia/internal/29
  244. 2016-06-15 13:05:24.409995 [DEBUG] switch_core_state_machine.c:60 sofia/internal/29 Standard HANGUP, cause: NORMAL_CLEARING
  245. 2016-06-15 13:05:24.409995 [DEBUG] switch_core_state_machine.c:811 (sofia/internal/29) State HANGUP going to sleep
  246. 2016-06-15 13:05:24.409995 [DEBUG] switch_core_session.c:2796 sofia/internal/21@192.168.30.36 skip receive message [PHONE_EVENT] (channel is hungup already)
  247. 2016-06-15 13:05:24.409995 [DEBUG] switch_core_state_machine.c:609 (sofia/internal/21@192.168.30.36) State EXECUTE going to sleep
  248. 2016-06-15 13:05:24.409995 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/21@192.168.30.36) Running State Change CS_HANGUP
  249. 2016-06-15 13:05:24.409995 [DEBUG] switch_core_state_machine.c:578 (sofia/internal/29) State Change CS_HANGUP -> CS_REPORTING
  250. 2016-06-15 13:05:24.409995 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/29) Running State Change CS_REPORTING
  251. 2016-06-15 13:05:24.409995 [DEBUG] switch_core_state_machine.c:897 (sofia/internal/29) State REPORTING
  252. 2016-06-15 13:05:24.409995 [DEBUG] switch_core_state_machine.c:174 sofia/internal/29 Standard REPORTING, cause: NORMAL_CLEARING
  253. 2016-06-15 13:05:24.409995 [DEBUG] switch_core_state_machine.c:897 (sofia/internal/29) State REPORTING going to sleep
  254. 2016-06-15 13:05:24.409995 [DEBUG] switch_core_state_machine.c:809 (sofia/internal/21@192.168.30.36) Callstate Change ACTIVE -> HANGUP
  255. 2016-06-15 13:05:24.409995 [DEBUG] switch_core_state_machine.c:811 (sofia/internal/21@192.168.30.36) State HANGUP
  256. 2016-06-15 13:05:24.409995 [DEBUG] mod_sofia.c:437 Channel sofia/internal/21@192.168.30.36 hanging up, cause: NORMAL_CLEARING
  257. 2016-06-15 13:05:24.409995 [DEBUG] switch_core_state_machine.c:60 sofia/internal/21@192.168.30.36 Standard HANGUP, cause: NORMAL_CLEARING
  258. 2016-06-15 13:05:24.409995 [DEBUG] switch_core_state_machine.c:811 (sofia/internal/21@192.168.30.36) State HANGUP going to sleep
  259. 2016-06-15 13:05:24.409995 [DEBUG] switch_core_state_machine.c:569 (sofia/internal/29) State Change CS_REPORTING -> CS_DESTROY
  260. 2016-06-15 13:05:24.409995 [DEBUG] switch_core_session.c:1646 Session 2 (sofia/internal/29) Locked, Waiting on external entities
  261. 2016-06-15 13:05:24.409995 [NOTICE] switch_core_session.c:1664 Session 2 (sofia/internal/29) Ended
  262. 2016-06-15 13:05:24.409995 [DEBUG] switch_core_state_machine.c:578 (sofia/internal/21@192.168.30.36) State Change CS_HANGUP -> CS_REPORTING
  263. 2016-06-15 13:05:24.409995 [NOTICE] switch_core_session.c:1668 Close Channel sofia/internal/29 [CS_DESTROY]
  264. 2016-06-15 13:05:24.409995 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/21@192.168.30.36) Running State Change CS_REPORTING
  265. 2016-06-15 13:05:24.409995 [DEBUG] switch_core_state_machine.c:897 (sofia/internal/21@192.168.30.36) State REPORTING
  266. 2016-06-15 13:05:24.409995 [DEBUG] switch_core_state_machine.c:174 sofia/internal/21@192.168.30.36 Standard REPORTING, cause: NORMAL_CLEARING
  267. 2016-06-15 13:05:24.409995 [DEBUG] switch_core_state_machine.c:897 (sofia/internal/21@192.168.30.36) State REPORTING going to sleep
  268. 2016-06-15 13:05:24.409995 [DEBUG] switch_core_state_machine.c:700 (sofia/internal/29) Running State Change CS_DESTROY
  269. 2016-06-15 13:05:24.409995 [DEBUG] switch_core_state_machine.c:710 (sofia/internal/29) State DESTROY
  270. 2016-06-15 13:05:24.409995 [DEBUG] mod_sofia.c:342 sofia/internal/29 SOFIA DESTROY
  271. 2016-06-15 13:05:24.409995 [DEBUG] mod_opus.c:661 Opus decoder stats: Frames[0] PLC[0] FEC[0]
  272. 2016-06-15 13:05:24.409995 [DEBUG] switch_core_state_machine.c:569 (sofia/internal/21@192.168.30.36) State Change CS_REPORTING -> CS_DESTROY
  273. 2016-06-15 13:05:24.409995 [DEBUG] switch_core_session.c:1646 Session 1 (sofia/internal/21@192.168.30.36) Locked, Waiting on external entities
  274. 2016-06-15 13:05:24.409995 [DEBUG] mod_opus.c:661 Opus decoder stats: Frames[0] PLC[0] FEC[0]
  275. 2016-06-15 13:05:24.409995 [NOTICE] switch_core_session.c:1664 Session 1 (sofia/internal/21@192.168.30.36) Ended
  276. 2016-06-15 13:05:24.409995 [NOTICE] switch_core_session.c:1668 Close Channel sofia/internal/21@192.168.30.36 [CS_DESTROY]
  277. 2016-06-15 13:05:24.409995 [DEBUG] switch_core_state_machine.c:181 sofia/internal/29 Standard DESTROY
  278. 2016-06-15 13:05:24.409995 [DEBUG] switch_core_state_machine.c:710 (sofia/internal/29) State DESTROY going to sleep
  279. 2016-06-15 13:05:24.409995 [DEBUG] switch_core_state_machine.c:700 (sofia/internal/21@192.168.30.36) Running State Change CS_DESTROY
  280. 2016-06-15 13:05:24.409995 [DEBUG] switch_core_state_machine.c:710 (sofia/internal/21@192.168.30.36) State DESTROY
  281. 2016-06-15 13:05:24.409995 [DEBUG] mod_sofia.c:342 sofia/internal/21@192.168.30.36 SOFIA DESTROY
  282. 2016-06-15 13:05:24.409995 [DEBUG] mod_opus.c:661 Opus decoder stats: Frames[0] PLC[0] FEC[0]
  283. 2016-06-15 13:05:24.409995 [DEBUG] mod_opus.c:661 Opus decoder stats: Frames[0] PLC[0] FEC[0]
  284. 2016-06-15 13:05:24.409995 [DEBUG] switch_core_state_machine.c:181 sofia/internal/21@192.168.30.36 Standard DESTROY
  285. 2016-06-15 13:05:24.409995 [DEBUG] switch_core_state_machine.c:710 (sofia/internal/21@192.168.30.36) State DESTROY going to sleep
  286. 2016-06-15 13:05:45.649982 [NOTICE] sofia_reg.c:448 Registering myn2p
  287. 2016-06-15 13:05:45.849978 [DEBUG] sofia_reg.c:2429 Changing expire time to 240 by request of proxy sip:72.55.165.151
  288.  
  289.