FreeSWITCH Pastebin

Untitled

From joshebosh, 7 Years ago, written in Plain Text.
- view diff
URL https://pastebin.freeswitch.org/view/c6cfb765
Embed
Download Paste or View Raw
  1. freeswitch@fs1>
  2. 2017-06-02 12:18:15.532836 [WARNING] switch_core_state_machine.c:687 1e81da34-4a69-482b-984e-bb96291ad115 sofia/internal/1@68.157.150.128 Abandoned
  3. 2017-06-02 12:18:15.532836 [NOTICE] switch_core_state_machine.c:690 Hangup sofia/internal/1@68.157.150.128 [CS_NEW] [WRONG_CALL_STATE]
  4. 2017-06-02 12:18:15.532836 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1@68.157.150.128) Running State Change CS_HANGUP (Cur 1 Tot 231)
  5. 2017-06-02 12:18:15.532836 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/1@68.157.150.128) Callstate Change DOWN -> HANGUP
  6. 2017-06-02 12:18:15.532836 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1@68.157.150.128) State HANGUP
  7. 2017-06-02 12:18:15.532836 [DEBUG] mod_sofia.c:449 Channel sofia/internal/1@68.157.150.128 hanging up, cause: WRONG_CALL_STATE
  8. 2017-06-02 12:18:15.532836 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1@68.157.150.128 Standard HANGUP, cause: WRONG_CALL_STATE
  9. 2017-06-02 12:18:15.532836 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1@68.157.150.128) State HANGUP going to sleep
  10. 2017-06-02 12:18:15.532836 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/1@68.157.150.128) State Change CS_HANGUP -> CS_REPORTING
  11. 2017-06-02 12:18:15.532836 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1@68.157.150.128) Running State Change CS_REPORTING (Cur 1 Tot 231)
  12. 2017-06-02 12:18:15.532836 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1@68.157.150.128) State REPORTING
  13. 2017-06-02 12:18:15.532836 [DEBUG] switch_core_state_machine.c:174 sofia/internal/1@68.157.150.128 Standard REPORTING, cause: WRONG_CALL_STATE
  14. 2017-06-02 12:18:15.532836 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1@68.157.150.128) State REPORTING going to sleep
  15. 2017-06-02 12:18:15.532836 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/1@68.157.150.128) State Change CS_REPORTING -> CS_DESTROY
  16. 2017-06-02 12:18:15.532836 [DEBUG] switch_core_session.c:1712 Session 231 (sofia/internal/1@68.157.150.128) Locked, Waiting on external entities
  17. 2017-06-02 12:18:15.532836 [NOTICE] switch_core_session.c:1730 Session 231 (sofia/internal/1@68.157.150.128) Ended
  18. 2017-06-02 12:18:15.532836 [NOTICE] switch_core_session.c:1734 Close Channel sofia/internal/1@68.157.150.128 [CS_DESTROY]
  19. 2017-06-02 12:18:15.532836 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/1@68.157.150.128) Running State Change CS_DESTROY (Cur 0 Tot 231)
  20. 2017-06-02 12:18:15.532836 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1@68.157.150.128) State DESTROY
  21. 2017-06-02 12:18:15.532836 [DEBUG] mod_sofia.c:354 sofia/internal/1@68.157.150.128 SOFIA DESTROY
  22. 2017-06-02 12:18:15.532836 [DEBUG] switch_core_state_machine.c:181 sofia/internal/1@68.157.150.128 Standard DESTROY
  23. 2017-06-02 12:18:15.532836 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1@68.157.150.128) State DESTROY going to sleep
  24. 2017-06-02 12:18:16.812835 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/1001@192.168.150.124 [5be54fde-a661-4390-9624-f603eed99e42]
  25. 2017-06-02 12:18:16.812835 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1001@192.168.150.124) Running State Change CS_NEW (Cur 1 Tot 232)
  26. 2017-06-02 12:18:16.812835 [DEBUG] sofia.c:10031 sofia/internal/1001@192.168.150.124 receiving invite from 192.168.150.102:5060 version: 1.9.0 git 6b3cef9 2017-06-01 23:40:50Z 64bit
  27. 2017-06-02 12:18:16.812835 [DEBUG] sofia.c:10202 IP 192.168.150.102 Rejected by acl "domains". Falling back to Digest auth.
  28. 2017-06-02 12:18:16.812835 [DEBUG] switch_core_state_machine.c:603 (sofia/internal/1001@192.168.150.124) State NEW
  29. 2017-06-02 12:18:16.812835 [DEBUG] sofia.c:2405 detaching session 5be54fde-a661-4390-9624-f603eed99e42
  30. 2017-06-02 12:18:16.822811 [DEBUG] sofia.c:2514 Re-attaching to session 5be54fde-a661-4390-9624-f603eed99e42
  31. 2017-06-02 12:18:16.832835 [DEBUG] sofia.c:10031 sofia/internal/1001@192.168.150.124 receiving invite from 192.168.150.102:5060 version: 1.9.0 git 6b3cef9 2017-06-01 23:40:50Z 64bit
  32. 2017-06-02 12:18:16.832835 [DEBUG] sofia.c:10202 IP 192.168.150.102 Rejected by acl "domains". Falling back to Digest auth.
  33. 2017-06-02 12:18:16.832835 [DEBUG] sofia.c:7247 Channel sofia/internal/1001@192.168.150.124 entering state [received][100]
  34. 2017-06-02 12:18:16.832835 [DEBUG] sofia.c:7257 Remote SDP:
  35. v=0
  36. o=1001 8000 8001 IN IP4 192.168.150.102
  37. s=SIP Call
  38. c=IN IP4 192.168.150.102
  39. t=0 0
  40. m=audio 5004 RTP/AVP 0 8 4 18 3 2 101
  41. a=rtpmap:0 PCMU/8000
  42. a=rtpmap:8 PCMA/8000
  43. a=rtpmap:4 G723/8000
  44. a=rtpmap:18 G729/8000
  45. a=rtpmap:3 GSM/8000
  46. a=rtpmap:2 G726-32/8000
  47. a=rtpmap:101 telephone-event/8000
  48. a=fmtp:101 0-11
  49. a=ptime:20
  50. m=video 5006 RTP/AVP 99 34 103
  51. a=rtpmap:99 H264/90000
  52. a=fmtp:99 profile-level-id=428014; packetization-mode=0; sprop-parameter-sets=Z0KADJWgUH5A,aM4Ecn==
  53. a=rtpmap:34 H263/90000
  54. a=fmtp:34 CIF=2 MaxBR=1280
  55. a=rtpmap:103 H263-1998/90000
  56. a=fmtp:103 CIF=2 MaxBR=1280
  57. a=framerate:15
  58.  
  59. 2017-06-02 12:18:16.832835 [DEBUG] sofia.c:7649 (sofia/internal/1001@192.168.150.124) State Change CS_NEW -> CS_INIT
  60. 2017-06-02 12:18:16.832835 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1001@192.168.150.124) Running State Change CS_INIT (Cur 1 Tot 232)
  61. 2017-06-02 12:18:16.832835 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1001@192.168.150.124) State INIT
  62. 2017-06-02 12:18:16.832835 [DEBUG] mod_sofia.c:93 sofia/internal/1001@192.168.150.124 SOFIA INIT
  63. 2017-06-02 12:18:16.832835 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1001@192.168.150.124 Standard INIT
  64. 2017-06-02 12:18:16.832835 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1001@192.168.150.124) State Change CS_INIT -> CS_ROUTING
  65. 2017-06-02 12:18:16.832835 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1001@192.168.150.124) State INIT going to sleep
  66. 2017-06-02 12:18:16.832835 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1001@192.168.150.124) Running State Change CS_ROUTING (Cur 1 Tot 232)
  67. 2017-06-02 12:18:16.832835 [DEBUG] switch_channel.c:2249 (sofia/internal/1001@192.168.150.124) Callstate Change DOWN -> RINGING
  68. 2017-06-02 12:18:16.832835 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1001@192.168.150.124) State ROUTING
  69. 2017-06-02 12:18:16.832835 [DEBUG] mod_sofia.c:154 sofia/internal/1001@192.168.150.124 SOFIA ROUTING
  70. 2017-06-02 12:18:16.832835 [DEBUG] switch_core_state_machine.c:236 sofia/internal/1001@192.168.150.124 Standard ROUTING
  71. 2017-06-02 12:18:16.832835 [INFO] mod_dialplan_xml.c:637 Processing 1001 <1001>->1010 in context default
  72. Dialplan: sofia/internal/1001@192.168.150.124 parsing [default->unloop] continue=false
  73. Dialplan: sofia/internal/1001@192.168.150.124 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
  74. Dialplan: sofia/internal/1001@192.168.150.124 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
  75. Dialplan: sofia/internal/1001@192.168.150.124 parsing [default->tod_example] continue=true
  76. Dialplan: sofia/internal/1001@192.168.150.124 Date/Time Match (PASS) [tod_example] break=on-false
  77. Dialplan: sofia/internal/1001@192.168.150.124 Action set(open=true)
  78. Dialplan: sofia/internal/1001@192.168.150.124 parsing [default->holiday_example] continue=true
  79. Dialplan: sofia/internal/1001@192.168.150.124 Date/TimeMatch (FAIL) [holiday_example] break=on-false
  80. Dialplan: sofia/internal/1001@192.168.150.124 parsing [default->global-intercept] continue=false
  81. Dialplan: sofia/internal/1001@192.168.150.124 Regex (FAIL) [global-intercept] destination_number(1010) =~ /^886$/ break=on-false
  82. Dialplan: sofia/internal/1001@192.168.150.124 parsing [default->group-intercept] continue=false
  83. Dialplan: sofia/internal/1001@192.168.150.124 Regex (FAIL) [group-intercept] destination_number(1010) =~ /^\*8$/ break=on-false
  84. Dialplan: sofia/internal/1001@192.168.150.124 parsing [default->intercept-ext] continue=false
  85. Dialplan: sofia/internal/1001@192.168.150.124 Regex (FAIL) [intercept-ext] destination_number(1010) =~ /^\*\*(\d+)$/ break=on-false
  86. Dialplan: sofia/internal/1001@192.168.150.124 parsing [default->redial] continue=false
  87. Dialplan: sofia/internal/1001@192.168.150.124 Regex (FAIL) [redial] destination_number(1010) =~ /^(redial|870)$/ break=on-false
  88. Dialplan: sofia/internal/1001@192.168.150.124 parsing [default->global] continue=true
  89. Dialplan: sofia/internal/1001@192.168.150.124 Regex (FAIL) [global] ${call_debug}(false) =~ /^true$/ break=never
  90. Dialplan: sofia/internal/1001@192.168.150.124 Regex (FAIL) [global] ${default_password}(j0sh3b0sh) =~ /^1234$/ break=never
  91. Dialplan: sofia/internal/1001@192.168.150.124 Regex (FAIL) [global] ${rtp_has_crypto}() =~ /^(AEAD_AES_256_GCM_8|AEAD_AES_128_GCM_8|AES_CM_256_HMAC_SHA1_80|AES_CM_192_HMAC_SHA1_80|AES_CM_128_HMAC_SHA1_80|AES_CM_256_HMAC_SHA1_32|AES_CM_192_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_32|AES_CM_128_NULL_AUTH)$/ break=never
  92. Dialplan: sofia/internal/1001@192.168.150.124 Regex (PASS) [global] ${endpoint_disposition}(DELAYED NEGOTIATION) =~ /^(DELAYED NEGOTIATION)/ break=on-false
  93. Dialplan: sofia/internal/1001@192.168.150.124 Regex (FAIL) [global] ${switch_r_sdp}(v=0
  94. o=1001 8000 8001 IN IP4 192.168.150.102
  95. s=SIP Call
  96. c=IN IP4 192.168.150.102
  97. t=0 0
  98. m=audio 5004 RTP/AVP 0 8 4 18 3 2 101
  99. a=rtpmap:0 PCMU/8000
  100. a=rtpmap:8 PCMA/8000
  101. a=rtpmap:4 G723/8000
  102. a=rtpmap:18 G729/8000
  103. a=rtpmap:3 GSM/8000
  104. a=rtpmap:2 G726-32/8000
  105. a=rtpmap:101 telephone-event/8000
  106. a=fmtp:101 0-11
  107. a=ptime:20
  108. m=video 5006 RTP/AVP 99 34 103
  109. a=rtpmap:99 H264/90000
  110. a=fmtp:99 profile-level-id=428014; packetization-mode=0; sprop-parameter-sets=Z0KADJWgUH5A,aM4Ecn==
  111. a=rtpmap:34 H263/90000
  112. a=fmtp:34 CIF=2 MaxBR=1280
  113. a=rtpmap:103 H263-1998/90000
  114. a=fmtp:103 CIF=2 MaxBR=1280
  115. a=framerate:15
  116. ) =~ /(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)/ break=never
  117. Dialplan: sofia/internal/1001@192.168.150.124 Absolute Condition [global]
  118. Dialplan: sofia/internal/1001@192.168.150.124 Action hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid})
  119. Dialplan: sofia/internal/1001@192.168.150.124 Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
  120. Dialplan: sofia/internal/1001@192.168.150.124 Action hash(insert/${domain_name}-last_dial/global/${uuid})
  121. Dialplan: sofia/internal/1001@192.168.150.124 Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
  122. Dialplan: sofia/internal/1001@192.168.150.124 parsing [default->snom-demo-2] continue=false
  123. Dialplan: sofia/internal/1001@192.168.150.124 Regex (FAIL) [snom-demo-2] destination_number(1010) =~ /^9001$/ break=on-false
  124. Dialplan: sofia/internal/1001@192.168.150.124 parsing [default->snom-demo-1] continue=false
  125. Dialplan: sofia/internal/1001@192.168.150.124 Regex (FAIL) [snom-demo-1] destination_number(1010) =~ /^9000$/ break=on-false
  126. Dialplan: sofia/internal/1001@192.168.150.124 parsing [default->eavesdrop] continue=false
  127. Dialplan: sofia/internal/1001@192.168.150.124 Regex (FAIL) [eavesdrop] destination_number(1010) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false
  128. Dialplan: sofia/internal/1001@192.168.150.124 parsing [default->eavesdrop] continue=false
  129. Dialplan: sofia/internal/1001@192.168.150.124 Regex (FAIL) [eavesdrop] destination_number(1010) =~ /^779$/ break=on-false
  130. Dialplan: sofia/internal/1001@192.168.150.124 parsing [default->call_return] continue=false
  131. Dialplan: sofia/internal/1001@192.168.150.124 Regex (FAIL) [call_return] destination_number(1010) =~ /^\*69$|^869$|^lcr$/ break=on-false
  132. Dialplan: sofia/internal/1001@192.168.150.124 parsing [default->del-group] continue=false
  133. Dialplan: sofia/internal/1001@192.168.150.124 Regex (FAIL) [del-group] destination_number(1010) =~ /^80(\d{2})$/ break=on-false
  134. Dialplan: sofia/internal/1001@192.168.150.124 parsing [default->add-group] continue=false
  135. Dialplan: sofia/internal/1001@192.168.150.124 Regex (FAIL) [add-group] destination_number(1010) =~ /^81(\d{2})$/ break=on-false
  136. Dialplan: sofia/internal/1001@192.168.150.124 parsing [default->call-group-simo] continue=false
  137. Dialplan: sofia/internal/1001@192.168.150.124 Regex (FAIL) [call-group-simo] destination_number(1010) =~ /^82(\d{2})$/ break=on-false
  138. Dialplan: sofia/internal/1001@192.168.150.124 parsing [default->call-group-order] continue=false
  139. Dialplan: sofia/internal/1001@192.168.150.124 Regex (FAIL) [call-group-order] destination_number(1010) =~ /^83(\d{2})$/ break=on-false
  140. Dialplan: sofia/internal/1001@192.168.150.124 parsing [default->extension-intercom] continue=false
  141. Dialplan: sofia/internal/1001@192.168.150.124 Regex (FAIL) [extension-intercom] destination_number(1010) =~ /^8(10[01][0-9])$/ break=on-false
  142. Dialplan: sofia/internal/1001@192.168.150.124 parsing [default->Local_Extension] continue=false
  143. Dialplan: sofia/internal/1001@192.168.150.124 Regex (PASS) [Local_Extension] destination_number(1010) =~ /^(10[01][0-9])$/ break=on-false
  144. Dialplan: sofia/internal/1001@192.168.150.124 Action export(dialed_extension=1010)
  145. Dialplan: sofia/internal/1001@192.168.150.124 Action bind_meta_app(1 b s execute_extension::dx XML features)
  146. Dialplan: sofia/internal/1001@192.168.150.124 Action bind_meta_app(2 b s record_session::/usr/local/freeswitch/recordings/${caller_id_number}.${strftime(%Y-%m-%d-%H-%M-%S)}.wav)
  147. Dialplan: sofia/internal/1001@192.168.150.124 Action bind_meta_app(3 b s execute_extension::cf XML features)
  148. Dialplan: sofia/internal/1001@192.168.150.124 Action bind_meta_app(4 b s execute_extension::att_xfer XML features)
  149. Dialplan: sofia/internal/1001@192.168.150.124 Action set(ringback=${us-ring})
  150. Dialplan: sofia/internal/1001@192.168.150.124 Action set(transfer_ringback=local_stream://moh)
  151. Dialplan: sofia/internal/1001@192.168.150.124 Action set(call_timeout=30)
  152. Dialplan: sofia/internal/1001@192.168.150.124 Action set(hangup_after_bridge=true)
  153. Dialplan: sofia/internal/1001@192.168.150.124 Action set(continue_on_fail=true)
  154. Dialplan: sofia/internal/1001@192.168.150.124 Action hash(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_number})
  155. Dialplan: sofia/internal/1001@192.168.150.124 Action hash(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid})
  156. Dialplan: sofia/internal/1001@192.168.150.124 Action set(called_party_callgroup=${user_data(${dialed_extension}@${domain_name} var callgroup)})
  157. Dialplan: sofia/internal/1001@192.168.150.124 Action hash(insert/${domain_name}-last_dial_ext/${called_party_callgroup}/${uuid})
  158. Dialplan: sofia/internal/1001@192.168.150.124 Action hash(insert/${domain_name}-last_dial_ext/global/${uuid})
  159. Dialplan: sofia/internal/1001@192.168.150.124 Action hash(insert/${domain_name}-last_dial/${called_party_callgroup}/${uuid})
  160. Dialplan: sofia/internal/1001@192.168.150.124 Action set(record_concat_video=true)
  161. Dialplan: sofia/internal/1001@192.168.150.124 Action record_session(/var/www/html/fs/${strftime(%Y-%m-%d_%H-%M-%S)}_${uuid}.mp4)
  162. Dialplan: sofia/internal/1001@192.168.150.124 Action bridge(user/${dialed_extension}@${domain_name})
  163. Dialplan: sofia/internal/1001@192.168.150.124 Action answer()
  164. Dialplan: sofia/internal/1001@192.168.150.124 Action sleep(1000)
  165. Dialplan: sofia/internal/1001@192.168.150.124 Action bridge(loopback/app=voicemail:default ${domain_name} ${dialed_extension})
  166. 2017-06-02 12:18:16.832835 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/1001@192.168.150.124) State Change CS_ROUTING -> CS_EXECUTE
  167. 2017-06-02 12:18:16.832835 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1001@192.168.150.124) State ROUTING going to sleep
  168. 2017-06-02 12:18:16.832835 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1001@192.168.150.124) Running State Change CS_EXECUTE (Cur 1 Tot 232)
  169. 2017-06-02 12:18:16.832835 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/1001@192.168.150.124) State EXECUTE
  170. 2017-06-02 12:18:16.832835 [DEBUG] mod_sofia.c:209 sofia/internal/1001@192.168.150.124 SOFIA EXECUTE
  171. 2017-06-02 12:18:16.832835 [DEBUG] switch_core_state_machine.c:328 sofia/internal/1001@192.168.150.124 Standard EXECUTE
  172. EXECUTE sofia/internal/1001@192.168.150.124 set(open=true)
  173. 2017-06-02 12:18:16.832835 [DEBUG] mod_dptools.c:1570 SET sofia/internal/1001@192.168.150.124 [open]=[true]
  174. EXECUTE sofia/internal/1001@192.168.150.124 hash(insert/192.168.150.124-spymap/1001/5be54fde-a661-4390-9624-f603eed99e42)
  175. EXECUTE sofia/internal/1001@192.168.150.124 hash(insert/192.168.150.124-last_dial/1001/1010)
  176. EXECUTE sofia/internal/1001@192.168.150.124 hash(insert/192.168.150.124-last_dial/global/5be54fde-a661-4390-9624-f603eed99e42)
  177. EXECUTE sofia/internal/1001@192.168.150.124 export(RFC2822_DATE=Fri, 02 Jun 2017 12:18:16 -0400)
  178. 2017-06-02 12:18:16.842804 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [RFC2822_DATE]=[Fri, 02 Jun 2017 12:18:16 -0400]
  179. EXECUTE sofia/internal/1001@192.168.150.124 export(dialed_extension=1010)
  180. 2017-06-02 12:18:16.842804 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [dialed_extension]=[1010]
  181. EXECUTE sofia/internal/1001@192.168.150.124 bind_meta_app(1 b s execute_extension::dx XML features)
  182. 2017-06-02 12:18:16.842804 [INFO] switch_ivr_async.c:4260 Bound B-Leg: *1 execute_extension::dx XML features
  183. EXECUTE sofia/internal/1001@192.168.150.124 bind_meta_app(2 b s record_session::/usr/local/freeswitch/recordings/1001.2017-06-02-12-18-16.wav)
  184. 2017-06-02 12:18:16.842804 [INFO] switch_ivr_async.c:4260 Bound B-Leg: *2 record_session::/usr/local/freeswitch/recordings/1001.2017-06-02-12-18-16.wav
  185. EXECUTE sofia/internal/1001@192.168.150.124 bind_meta_app(3 b s execute_extension::cf XML features)
  186. 2017-06-02 12:18:16.842804 [INFO] switch_ivr_async.c:4260 Bound B-Leg: *3 execute_extension::cf XML features
  187. EXECUTE sofia/internal/1001@192.168.150.124 bind_meta_app(4 b s execute_extension::att_xfer XML features)
  188. 2017-06-02 12:18:16.842804 [INFO] switch_ivr_async.c:4260 Bound B-Leg: *4 execute_extension::att_xfer XML features
  189. EXECUTE sofia/internal/1001@192.168.150.124 set(ringback=%(2000,4000,440,480))
  190. 2017-06-02 12:18:16.842804 [DEBUG] mod_dptools.c:1570 SET sofia/internal/1001@192.168.150.124 [ringback]=[%(2000,4000,440,480)]
  191. EXECUTE sofia/internal/1001@192.168.150.124 set(transfer_ringback=local_stream://moh)
  192. 2017-06-02 12:18:16.842804 [DEBUG] mod_dptools.c:1570 SET sofia/internal/1001@192.168.150.124 [transfer_ringback]=[local_stream://moh]
  193. EXECUTE sofia/internal/1001@192.168.150.124 set(call_timeout=30)
  194. 2017-06-02 12:18:16.842804 [DEBUG] mod_dptools.c:1570 SET sofia/internal/1001@192.168.150.124 [call_timeout]=[30]
  195. EXECUTE sofia/internal/1001@192.168.150.124 set(hangup_after_bridge=true)
  196. 2017-06-02 12:18:16.842804 [DEBUG] mod_dptools.c:1570 SET sofia/internal/1001@192.168.150.124 [hangup_after_bridge]=[true]
  197. EXECUTE sofia/internal/1001@192.168.150.124 set(continue_on_fail=true)
  198. 2017-06-02 12:18:16.842804 [DEBUG] mod_dptools.c:1570 SET sofia/internal/1001@192.168.150.124 [continue_on_fail]=[true]
  199. EXECUTE sofia/internal/1001@192.168.150.124 hash(insert/192.168.150.124-call_return/1010/1001)
  200. EXECUTE sofia/internal/1001@192.168.150.124 hash(insert/192.168.150.124-last_dial_ext/1010/5be54fde-a661-4390-9624-f603eed99e42)
  201. EXECUTE sofia/internal/1001@192.168.150.124 set(called_party_callgroup=techsupport)
  202. 2017-06-02 12:18:16.842804 [DEBUG] mod_dptools.c:1570 SET sofia/internal/1001@192.168.150.124 [called_party_callgroup]=[techsupport]
  203. EXECUTE sofia/internal/1001@192.168.150.124 hash(insert/192.168.150.124-last_dial_ext/techsupport/5be54fde-a661-4390-9624-f603eed99e42)
  204. EXECUTE sofia/internal/1001@192.168.150.124 hash(insert/192.168.150.124-last_dial_ext/global/5be54fde-a661-4390-9624-f603eed99e42)
  205. EXECUTE sofia/internal/1001@192.168.150.124 hash(insert/192.168.150.124-last_dial/techsupport/5be54fde-a661-4390-9624-f603eed99e42)
  206. EXECUTE sofia/internal/1001@192.168.150.124 set(record_concat_video=true)
  207. 2017-06-02 12:18:16.842804 [DEBUG] mod_dptools.c:1570 SET sofia/internal/1001@192.168.150.124 [record_concat_video]=[true]
  208. 2017-06-02 12:18:16.842804 [DEBUG] switch_core_session.c:2707 Application record_session Requires media! pre_answering channel sofia/internal/1001@192.168.150.124
  209. 2017-06-02 12:18:16.842804 [INFO] switch_core_session.c:2709 Sending early media
  210. 2017-06-02 12:18:16.842804 [DEBUG] switch_core_media.c:5111 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1]
  211. 2017-06-02 12:18:16.842804 [DEBUG] switch_core_media.c:5111 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  212. 2017-06-02 12:18:16.842804 [DEBUG] switch_core_media.c:5111 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  213. 2017-06-02 12:18:16.842804 [DEBUG] switch_core_media.c:5166 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
  214. 2017-06-02 12:18:16.842804 [DEBUG] switch_core_media.c:5111 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  215. 2017-06-02 12:18:16.842804 [DEBUG] switch_core_media.c:5111 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1]
  216. 2017-06-02 12:18:16.842804 [DEBUG] switch_core_media.c:5111 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  217. 2017-06-02 12:18:16.842804 [DEBUG] switch_core_media.c:5111 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  218. 2017-06-02 12:18:16.842804 [DEBUG] switch_core_media.c:5111 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  219. 2017-06-02 12:18:16.842804 [DEBUG] switch_core_media.c:5166 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
  220. 2017-06-02 12:18:16.842804 [DEBUG] switch_core_media.c:5111 Audio Codec Compare [G723:4:8000:20:6300:1]/[opus:116:48000:20:0:1]
  221. 2017-06-02 12:18:16.842804 [DEBUG] switch_core_media.c:5111 Audio Codec Compare [G723:4:8000:20:6300:1]/[G722:9:8000:20:64000:1]
  222. 2017-06-02 12:18:16.842804 [DEBUG] switch_core_media.c:5111 Audio Codec Compare [G723:4:8000:20:6300:1]/[PCMU:0:8000:20:64000:1]
  223. 2017-06-02 12:18:16.842804 [DEBUG] switch_core_media.c:5111 Audio Codec Compare [G723:4:8000:20:6300:1]/[PCMA:8:8000:20:64000:1]
  224. 2017-06-02 12:18:16.842804 [DEBUG] switch_core_media.c:5111 Audio Codec Compare [G729:18:8000:20:8000:1]/[opus:116:48000:20:0:1]
  225. 2017-06-02 12:18:16.842804 [DEBUG] switch_core_media.c:5111 Audio Codec Compare [G729:18:8000:20:8000:1]/[G722:9:8000:20:64000:1]
  226. 2017-06-02 12:18:16.842804 [DEBUG] switch_core_media.c:5111 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
  227. 2017-06-02 12:18:16.842804 [DEBUG] switch_core_media.c:5111 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
  228. 2017-06-02 12:18:16.842804 [DEBUG] switch_core_media.c:5111 Audio Codec Compare [GSM:3:8000:20:13200:1]/[opus:116:48000:20:0:1]
  229. 2017-06-02 12:18:16.842804 [DEBUG] switch_core_media.c:5111 Audio Codec Compare [GSM:3:8000:20:13200:1]/[G722:9:8000:20:64000:1]
  230. 2017-06-02 12:18:16.842804 [DEBUG] switch_core_media.c:5111 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMU:0:8000:20:64000:1]
  231. 2017-06-02 12:18:16.842804 [DEBUG] switch_core_media.c:5111 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMA:8:8000:20:64000:1]
  232. 2017-06-02 12:18:16.842804 [DEBUG] switch_core_media.c:5111 Audio Codec Compare [G726-32:2:8000:20:0:1]/[opus:116:48000:20:0:1]
  233. 2017-06-02 12:18:16.842804 [DEBUG] switch_core_media.c:5111 Audio Codec Compare [G726-32:2:8000:20:0:1]/[G722:9:8000:20:64000:1]
  234. 2017-06-02 12:18:16.842804 [DEBUG] switch_core_media.c:5111 Audio Codec Compare [G726-32:2:8000:20:0:1]/[PCMU:0:8000:20:64000:1]
  235. 2017-06-02 12:18:16.842804 [DEBUG] switch_core_media.c:5111 Audio Codec Compare [G726-32:2:8000:20:0:1]/[PCMA:8:8000:20:64000:1]
  236. 2017-06-02 12:18:16.842804 [DEBUG] switch_core_media.c:5027 Set telephone-event payload to 101@8000
  237. 2017-06-02 12:18:16.842804 [DEBUG] switch_core_media.c:3426 Set Codec sofia/internal/1001@192.168.150.124 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
  238. 2017-06-02 12:18:16.842804 [DEBUG] switch_core_codec.c:111 sofia/internal/1001@192.168.150.124 Original read codec set to PCMU:0
  239. 2017-06-02 12:18:16.842804 [DEBUG] switch_core_media.c:5370 Set telephone-event payload to 101@8000
  240. 2017-06-02 12:18:16.842804 [DEBUG] switch_core_media.c:5428 sofia/internal/1001@192.168.150.124 Set 2833 dtmf send payload to 101 recv payload to 101
  241. 2017-06-02 12:18:16.842804 [DEBUG] switch_core_media.c:5711 Video Codec Compare [H264:99]/[VP8:99]
  242. 2017-06-02 12:18:16.842804 [DEBUG] switch_core_media.c:5711 Video Codec Compare [H264:99]/[H264:99]
  243. 2017-06-02 12:18:16.842804 [DEBUG] switch_core_media.c:5743 Video Codec Compare [H264:99] +++ is saved as a match
  244. 2017-06-02 12:18:16.842804 [DEBUG] switch_core_media.c:5711 Video Codec Compare [H263:34]/[VP8:99]
  245. 2017-06-02 12:18:16.842804 [DEBUG] switch_core_media.c:5711 Video Codec Compare [H263:34]/[H264:99]
  246. 2017-06-02 12:18:16.842804 [DEBUG] switch_core_media.c:5711 Video Codec Compare [H263-1998:103]/[VP8:99]
  247. 2017-06-02 12:18:16.842804 [DEBUG] switch_core_media.c:5711 Video Codec Compare [H263-1998:103]/[H264:99]
  248. 2017-06-02 12:18:16.842804 [NOTICE] avcodec.c:1019 codec: id=28 H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10
  249. 2017-06-02 12:18:16.842804 [NOTICE] avcodec.c:1019 codec: id=28 H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10
  250. 2017-06-02 12:18:16.842804 [DEBUG] switch_core_media.c:3236 Set VIDEO Codec sofia/internal/1001@192.168.150.124 H264/90000 0 ms
  251. 2017-06-02 12:18:16.842804 [DEBUG] switch_core_media.c:8145 AUDIO RTP [sofia/internal/1001@192.168.150.124] 192.168.150.124 port 26284 -> 192.168.150.102 port 5004 codec: 0 ms: 20
  252. 2017-06-02 12:18:16.842804 [DEBUG] switch_rtp.c:4108 Starting timer [soft] 160 bytes per 20ms
  253. 2017-06-02 12:18:16.842804 [DEBUG] switch_core_media.c:8448 sofia/internal/1001@192.168.150.124 Set 2833 dtmf send payload to 101
  254. 2017-06-02 12:18:16.842804 [DEBUG] switch_core_media.c:8455 sofia/internal/1001@192.168.150.124 Set 2833 dtmf receive payload to 101
  255. 2017-06-02 12:18:16.842804 [DEBUG] switch_core_media.c:8478 sofia/internal/1001@192.168.150.124 Set rtp dtmf delay to 40
  256. 2017-06-02 12:18:16.842804 [DEBUG] switch_rtp.c:4123 Starting video timer.
  257. 2017-06-02 12:18:16.852805 [DEBUG] switch_core_media.c:8973 VIDEO RTP [sofia/internal/1001@192.168.150.124] 192.168.150.124:18850->192.168.150.102:5006 codec: 99 ms: 0 [SUCCESS]
  258. 2017-06-02 12:18:16.852805 [DEBUG] switch_core_media.c:7137 sofia/internal/1001@192.168.150.124 Starting Video thread
  259. 2017-06-02 12:18:16.852805 [DEBUG] switch_core_media.c:7003 sofia/internal/1001@192.168.150.124 Video thread started. Echo is off
  260. 2017-06-02 12:18:16.852805 [NOTICE] sofia_media.c:92 Pre-Answer sofia/internal/1001@192.168.150.124!
  261. 2017-06-02 12:18:16.852805 [DEBUG] switch_channel.c:3481 (sofia/internal/1001@192.168.150.124) Callstate Change RINGING -> EARLY
  262. 2017-06-02 12:18:16.852805 [DEBUG] switch_core_media.c:8128 Audio params are unchanged for sofia/internal/1001@192.168.150.124.
  263. 2017-06-02 12:18:16.852805 [DEBUG] switch_core_media.c:8831 Video params are unchanged for sofia/internal/1001@192.168.150.124.
  264. 2017-06-02 12:18:16.852805 [DEBUG] mod_sofia.c:2512 Ring SDP:
  265. v=0
  266. o=FreeSWITCH 1496394012 1496394013 IN IP4 192.168.150.124
  267. s=FreeSWITCH
  268. c=IN IP4 192.168.150.124
  269. t=0 0
  270. m=audio 26284 RTP/AVP 0 101
  271. a=rtpmap:0 PCMU/8000
  272. a=rtpmap:101 telephone-event/8000
  273. a=fmtp:101 0-16
  274. a=ptime:20
  275. a=sendrecv
  276. m=video 18850 RTP/AVP 99
  277. b=AS:1024
  278. a=rtpmap:99 H264/90000
  279. a=fmtp:99 profile-level-id=428014; packetization-mode=0; sprop-parameter-sets=Z0KADJWgUH5A,aM4Ecn==
  280. a=sendrecv
  281.  
  282. EXECUTE sofia/internal/1001@192.168.150.124 record_session(/var/www/html/fs/2017-06-02_12-18-16_5be54fde-a661-4390-9624-f603eed99e42.mp4)
  283. 2017-06-02 12:18:16.852805 [DEBUG] avformat.c:1851 sample rate: 8000, channels: 2
  284. 2017-06-02 12:18:16.852805 [DEBUG] avformat.c:1956 use video codec: [28] h264 (H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10)
  285. 2017-06-02 12:18:16.852805 [NOTICE] avformat.c:640 sample_rate: 8000 nb_samples: 1024
  286. 2017-06-02 12:18:16.852805 [INFO] avformat.c:1980 Opening File [/var/www/html/fs/2017-06-02_12-18-16_5be54fde-a661-4390-9624-f603eed99e42.mp4] 8000hz  with VIDEO
  287. 2017-06-02 12:18:16.852805 [DEBUG] sofia.c:7247 Channel sofia/internal/1001@192.168.150.124 entering state [early][183]
  288. 2017-06-02 12:18:16.862804 [DEBUG] switch_core_media_bug.c:962 Attaching BUG to sofia/internal/1001@192.168.150.124
  289. EXECUTE sofia/internal/1001@192.168.150.124 bridge(user/1010@192.168.150.124)
  290. 2017-06-02 12:18:16.862804 [DEBUG] switch_channel.c:1250 sofia/internal/1001@192.168.150.124 EXPORTING[export_vars] [RFC2822_DATE]=[Fri, 02 Jun 2017 12:18:16 -0400] to event
  291. 2017-06-02 12:18:16.862804 [DEBUG] switch_channel.c:1250 sofia/internal/1001@192.168.150.124 EXPORTING[export_vars] [dialed_extension]=[1010] to event
  292. 2017-06-02 12:18:16.862804 [DEBUG] switch_ivr_originate.c:2147 Parsing global variables
  293. 2017-06-02 12:18:16.862804 [DEBUG] switch_channel.c:1250 sofia/internal/1001@192.168.150.124 EXPORTING[export_vars] [RFC2822_DATE]=[Fri, 02 Jun 2017 12:18:16 -0400] to event
  294. 2017-06-02 12:18:16.862804 [DEBUG] switch_channel.c:1250 sofia/internal/1001@192.168.150.124 EXPORTING[export_vars] [dialed_extension]=[1010] to event
  295. 2017-06-02 12:18:16.862804 [DEBUG] switch_ivr_originate.c:2147 Parsing global variables
  296. 2017-06-02 12:18:16.862804 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/1010@192.168.150.103:5060 [daee73d2-3b9d-4241-9dcb-6bb71b0bcb0e]
  297. 2017-06-02 12:18:16.862804 [DEBUG] mod_sofia.c:5026 (sofia/internal/1010@192.168.150.103:5060) State Change CS_NEW -> CS_INIT
  298. 2017-06-02 12:18:16.862804 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1010@192.168.150.103:5060) Running State Change CS_INIT (Cur 2 Tot 233)
  299. 2017-06-02 12:18:16.862804 [NOTICE] switch_ivr_originate.c:2856 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
  300. 2017-06-02 12:18:16.862804 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1010@192.168.150.103:5060) State INIT
  301. 2017-06-02 12:18:16.862804 [DEBUG] mod_sofia.c:93 sofia/internal/1010@192.168.150.103:5060 SOFIA INIT
  302. 2017-06-02 12:18:16.862804 [DEBUG] sofia_glue.c:1298 sofia/internal/1010@192.168.150.103:5060 sending invite version: 1.9.0 git 6b3cef9 2017-06-01 23:40:50Z 64bit
  303. Local SDP:
  304. v=0
  305. o=FreeSWITCH 1496402746 1496402747 IN IP4 192.168.150.124
  306. s=FreeSWITCH
  307. c=IN IP4 192.168.150.124
  308. t=0 0
  309. m=audio 17550 RTP/AVP 0 101
  310. a=rtpmap:0 PCMU/8000
  311. a=rtpmap:101 telephone-event/8000
  312. a=fmtp:101 0-16
  313. a=ptime:20
  314. a=sendrecv
  315. m=video 28398 RTP/AVP 102
  316. b=AS:1024
  317. a=rtpmap:102 H264/90000
  318. a=fmtp:102 profile-level-id=428014; packetization-mode=0; sprop-parameter-sets=Z0KADJWgUH5A,aM4Ecn==
  319. a=sendrecv
  320. a=rtcp-fb:102 ccm fir
  321. a=rtcp-fb:102 ccm tmmbr
  322. a=rtcp-fb:102 nack
  323. a=rtcp-fb:102 nack pli
  324.  
  325. 2017-06-02 12:18:16.862804 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1010@192.168.150.103:5060 Standard INIT
  326. 2017-06-02 12:18:16.862804 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1010@192.168.150.103:5060) State Change CS_INIT -> CS_ROUTING
  327. 2017-06-02 12:18:16.862804 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1010@192.168.150.103:5060) State INIT going to sleep
  328. 2017-06-02 12:18:16.862804 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1010@192.168.150.103:5060) Running State Change CS_ROUTING (Cur 2 Tot 233)
  329. 2017-06-02 12:18:16.862804 [DEBUG] sofia.c:7247 Channel sofia/internal/1010@192.168.150.103:5060 entering state [calling][0]
  330. 2017-06-02 12:18:16.862804 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1010@192.168.150.103:5060) State ROUTING
  331. 2017-06-02 12:18:16.862804 [DEBUG] mod_sofia.c:154 sofia/internal/1010@192.168.150.103:5060 SOFIA ROUTING
  332. 2017-06-02 12:18:16.862804 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/1010@192.168.150.103:5060) State Change CS_ROUTING -> CS_CONSUME_MEDIA
  333. 2017-06-02 12:18:16.862804 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1010@192.168.150.103:5060) State ROUTING going to sleep
  334. 2017-06-02 12:18:16.862804 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1010@192.168.150.103:5060) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 233)
  335. 2017-06-02 12:18:16.862804 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/1010@192.168.150.103:5060) State CONSUME_MEDIA
  336. 2017-06-02 12:18:16.862804 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/1010@192.168.150.103:5060) State CONSUME_MEDIA going to sleep
  337. 2017-06-02 12:18:16.862804 [DEBUG] switch_ivr_async.c:1508 No silence detection configured; assuming start of speech
  338. 2017-06-02 12:18:16.872806 [INFO] avcodec.c:1077 initializing encoder 352x288
  339. 2017-06-02 12:18:16.872806 [DEBUG] avcodec.c:831 NVENC HW CODEC NOT PRESENT
  340. 2017-06-02 12:18:16.872806 [DEBUG] sofia.c:7247 Channel sofia/internal/1010@192.168.150.103:5060 entering state [proceeding][180]
  341. 2017-06-02 12:18:16.872806 [NOTICE] sofia.c:7355 Ring-Ready sofia/internal/1010@192.168.150.103:5060!
  342. 2017-06-02 12:18:16.872806 [DEBUG] switch_channel.c:3353 (sofia/internal/1010@192.168.150.103:5060) Callstate Change DOWN -> RINGING
  343. 2017-06-02 12:18:16.882809 [DEBUG] switch_rtp.c:7267 Correct audio ip/port confirmed.
  344. 2017-06-02 12:18:16.882809 [DEBUG] switch_core_io.c:448 Setting BUG Codec PCMU:0
  345. 2017-06-02 12:18:16.902835 [DEBUG] switch_ivr_originate.c:1278 Raw Codec Activation Success L16@8000hz 1 channel 20ms
  346. 2017-06-02 12:18:16.902835 [DEBUG] switch_core_codec.c:223 sofia/internal/1001@192.168.150.124 Push codec L16:100
  347. 2017-06-02 12:18:16.902835 [DEBUG] switch_ivr_originate.c:1347 Play Ringback Tone [%(2000,4000,440,480)]
  348. 2017-06-02 12:18:16.942808 [INFO] avformat.c:2610 use video codec implementation Video: libx264, yuv420p, 1280x720, q=10-31
  349. 2017-06-02 12:18:16.942808 [NOTICE] avformat.c:722 video thread start
  350. 2017-06-02 12:18:17.452835 [ERR] avformat.c:2131 Error while writing audio frame: Invalid argument
  351. 2017-06-02 12:18:17.462812 [DEBUG] switch_rtp.c:7267 Correct video ip/port confirmed.
  352. 2017-06-02 12:18:18.902835 [DEBUG] sofia.c:7247 Channel sofia/internal/1010@192.168.150.103:5060 entering state [completing][200]
  353. 2017-06-02 12:18:18.902835 [DEBUG] sofia.c:7257 Remote SDP:
  354. v=0
  355. o=1010 8000 8000 IN IP4 192.168.150.103
  356. s=SIP Call
  357. c=IN IP4 192.168.150.103
  358. t=0 0
  359. m=audio 5004 RTP/AVP 0 101
  360. a=rtpmap:0 PCMU/8000
  361. a=rtpmap:101 telephone-event/8000
  362. a=fmtp:101 0-11
  363. a=ptime:20
  364. m=video 5006 RTP/AVP 102
  365. a=rtpmap:102 H264/90000
  366. a=fmtp:102 profile-level-id=428014; packetization-mode=0; sprop-parameter-sets=Z0KADJWgUH5A,aM4Ecs==
  367. a=framerate:15
  368.  
  369. 2017-06-02 12:18:18.902835 [DEBUG] sofia.c:7247 Channel sofia/internal/1010@192.168.150.103:5060 entering state [ready][200]
  370. 2017-06-02 12:18:18.902835 [DEBUG] switch_core_media.c:5111 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  371. 2017-06-02 12:18:18.902835 [DEBUG] switch_core_media.c:5166 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
  372. 2017-06-02 12:18:18.902835 [DEBUG] switch_core_media.c:5027 Set telephone-event payload to 101@8000
  373. 2017-06-02 12:18:18.902835 [DEBUG] switch_core_media.c:3426 Set Codec sofia/internal/1010@192.168.150.103:5060 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
  374. 2017-06-02 12:18:18.902835 [DEBUG] switch_core_codec.c:111 sofia/internal/1010@192.168.150.103:5060 Original read codec set to PCMU:0
  375. 2017-06-02 12:18:18.902835 [DEBUG] switch_core_media.c:5370 Set telephone-event payload to 101@8000
  376. 2017-06-02 12:18:18.902835 [DEBUG] switch_core_media.c:5428 sofia/internal/1010@192.168.150.103:5060 Set 2833 dtmf send payload to 101 recv payload to 101
  377. 2017-06-02 12:18:18.902835 [DEBUG] switch_core_media.c:5711 Video Codec Compare [H264:102]/[H264:99]
  378. 2017-06-02 12:18:18.902835 [DEBUG] switch_core_media.c:5754 No matches with FTMP, fallback to ignoring FMTP
  379. 2017-06-02 12:18:18.902835 [DEBUG] switch_core_media.c:5711 Video Codec Compare [H264:102]/[H264:99]
  380. 2017-06-02 12:18:18.902835 [DEBUG] switch_core_media.c:5762 No matches with inherit_codec, fallback to ignoring PT
  381. 2017-06-02 12:18:18.902835 [DEBUG] switch_core_media.c:5711 Video Codec Compare [H264:102]/[H264:99]
  382. 2017-06-02 12:18:18.902835 [DEBUG] switch_core_media.c:5743 Video Codec Compare [H264:102] +++ is saved as a match
  383. 2017-06-02 12:18:18.902835 [NOTICE] avcodec.c:1019 codec: id=28 H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10
  384. 2017-06-02 12:18:18.902835 [NOTICE] avcodec.c:1019 codec: id=28 H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10
  385. 2017-06-02 12:18:18.902835 [DEBUG] switch_core_media.c:3236 Set VIDEO Codec sofia/internal/1010@192.168.150.103:5060 H264/90000 0 ms
  386. 2017-06-02 12:18:18.902835 [DEBUG] switch_core_media.c:8145 AUDIO RTP [sofia/internal/1010@192.168.150.103:5060] 192.168.150.124 port 17550 -> 192.168.150.103 port 5004 codec: 0 ms: 20
  387. 2017-06-02 12:18:18.902835 [DEBUG] switch_rtp.c:4108 Starting timer [soft] 160 bytes per 20ms
  388. 2017-06-02 12:18:18.902835 [DEBUG] switch_core_media.c:8448 sofia/internal/1010@192.168.150.103:5060 Set 2833 dtmf send payload to 101
  389. 2017-06-02 12:18:18.902835 [DEBUG] switch_core_media.c:8455 sofia/internal/1010@192.168.150.103:5060 Set 2833 dtmf receive payload to 101
  390. 2017-06-02 12:18:18.902835 [DEBUG] switch_core_media.c:8478 sofia/internal/1010@192.168.150.103:5060 Set rtp dtmf delay to 40
  391. 2017-06-02 12:18:18.902835 [DEBUG] switch_rtp.c:4123 Starting video timer.
  392. 2017-06-02 12:18:18.912807 [DEBUG] switch_core_media.c:8973 VIDEO RTP [sofia/internal/1010@192.168.150.103:5060] 192.168.150.124:28398->192.168.150.103:5006 codec: 102 ms: 0 [SUCCESS]
  393. 2017-06-02 12:18:18.912807 [DEBUG] switch_core_media.c:7137 sofia/internal/1010@192.168.150.103:5060 Starting Video thread
  394. 2017-06-02 12:18:18.912807 [DEBUG] switch_core_media.c:7003 sofia/internal/1010@192.168.150.103:5060 Video thread started. Echo is off
  395. 2017-06-02 12:18:18.912807 [NOTICE] sofia.c:8383 Channel [sofia/internal/1010@192.168.150.103:5060] has been answered
  396. 2017-06-02 12:18:18.912807 [DEBUG] switch_channel.c:3780 (sofia/internal/1010@192.168.150.103:5060) Callstate Change RINGING -> ACTIVE
  397. 2017-06-02 12:18:18.922810 [DEBUG] switch_core_codec.c:248 sofia/internal/1001@192.168.150.124 Restore previous codec PCMU:0.
  398. 2017-06-02 12:18:18.922810 [DEBUG] switch_core_media.c:8128 Audio params are unchanged for sofia/internal/1001@192.168.150.124.
  399. 2017-06-02 12:18:18.922810 [DEBUG] switch_core_media.c:8831 Video params are unchanged for sofia/internal/1001@192.168.150.124.
  400. 2017-06-02 12:18:18.922810 [DEBUG] mod_sofia.c:881 Local SDP sofia/internal/1001@192.168.150.124:
  401. v=0
  402. o=FreeSWITCH 1496394012 1496394014 IN IP4 192.168.150.124
  403. s=FreeSWITCH
  404. c=IN IP4 192.168.150.124
  405. t=0 0
  406. m=audio 26284 RTP/AVP 0 101
  407. a=rtpmap:0 PCMU/8000
  408. a=rtpmap:101 telephone-event/8000
  409. a=fmtp:101 0-16
  410. a=ptime:20
  411. a=sendrecv
  412. m=video 18850 RTP/AVP 99
  413. b=AS:1024
  414. a=rtpmap:99 H264/90000
  415. a=fmtp:99 profile-level-id=428014; packetization-mode=0; sprop-parameter-sets=Z0KADJWgUH5A,aM4Ecn==
  416. a=sendrecv
  417.  
  418. 2017-06-02 12:18:18.922810 [NOTICE] switch_ivr_originate.c:3652 Channel [sofia/internal/1001@192.168.150.124] has been answered
  419. 2017-06-02 12:18:18.932807 [DEBUG] switch_channel.c:3780 (sofia/internal/1001@192.168.150.124) Callstate Change EARLY -> ACTIVE
  420. 2017-06-02 12:18:18.932807 [DEBUG] sofia.c:7247 Channel sofia/internal/1001@192.168.150.124 entering state [completed][200]
  421. 2017-06-02 12:18:18.932807 [DEBUG] switch_ivr_originate.c:3710 Originate Resulted in Success: [sofia/internal/1010@192.168.150.103:5060]
  422. 2017-06-02 12:18:18.932807 [DEBUG] switch_ivr_originate.c:3710 Originate Resulted in Success: [sofia/internal/1010@192.168.150.103:5060]
  423. 2017-06-02 12:18:18.932807 [DEBUG] sofia.c:7247 Channel sofia/internal/1001@192.168.150.124 entering state [ready][200]
  424. 2017-06-02 12:18:18.932807 [DEBUG] switch_ivr_bridge.c:1744 (sofia/internal/1010@192.168.150.103:5060) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
  425. 2017-06-02 12:18:18.932807 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1010@192.168.150.103:5060) Running State Change CS_EXCHANGE_MEDIA (Cur 2 Tot 233)
  426. 2017-06-02 12:18:18.932807 [DEBUG] switch_core_state_machine.c:653 (sofia/internal/1010@192.168.150.103:5060) State EXCHANGE_MEDIA
  427. 2017-06-02 12:18:18.932807 [DEBUG] mod_sofia.c:645 SOFIA EXCHANGE_MEDIA
  428. 2017-06-02 12:18:18.942835 [INFO] avcodec.c:1077 initializing encoder 352x288
  429. 2017-06-02 12:18:18.942835 [DEBUG] avcodec.c:831 NVENC HW CODEC NOT PRESENT
  430. 2017-06-02 12:18:18.942835 [DEBUG] switch_rtp.c:7267 Correct video ip/port confirmed.
  431. 2017-06-02 12:18:18.962812 [DEBUG] switch_rtp.c:7267 Correct audio ip/port confirmed.
  432. 2017-06-02 12:18:18.982810 [DEBUG] switch_rtp.c:7267 Correct audio ip/port confirmed.
  433. 2017-06-02 12:18:19.002834 [DEBUG] switch_rtp.c:7267 Correct video ip/port confirmed.
  434. 2017-06-02 12:18:19.012805 [DEBUG] avcodec.c:1085 picture size changed from 352x288 to 320x240, reinitializing encoder
  435. 2017-06-02 12:18:19.122809 [DEBUG] switch_ivr.c:624 sofia/internal/1010@192.168.150.103:5060 Command Execute lua(record_details.lua)
  436. EXECUTE sofia/internal/1010@192.168.150.103:5060 lua(record_details.lua)
  437. 2017-06-02 12:18:19.122809 [ERR] mod_lua.cpp:203 /usr/local/freeswitch/scripts/record_details.lua:18: attempt to concatenate a nil value
  438. stack traceback:
  439.         /usr/local/freeswitch/scripts/record_details.lua:18: in main chunk
  440. 2017-06-02 12:18:19.122809 [DEBUG] switch_cpp.cpp:1122 sofia/internal/1010@192.168.150.103:5060 destroy/unlink session from object
  441. 2017-06-02 12:18:19.132811 [DEBUG] avcodec.c:1085 picture size changed from 352x288 to 320x240, reinitializing encoder
  442. 2017-06-02 12:18:19.162809 [DEBUG] switch_ivr.c:624 sofia/internal/1001@192.168.150.124 Command Execute lua(record_details.lua)
  443. EXECUTE sofia/internal/1001@192.168.150.124 lua(record_details.lua)
  444. 2017-06-02 12:18:19.162809 [INFO] switch_cpp.cpp:1303
  445.  
  446.  
  447.  
  448.  
  449.  
  450.  
  451.  
  452.  
  453.  
  454. uuid,5be54fde-a661-4390-9624-f603eed99e42
  455. direction,inbound
  456. channel_name,sofia/internal/1001@192.168.150.124
  457. caller_id_number,1001
  458. read_codec,PCMU
  459. read_rate,8000
  460. write_codec,PCMU
  461. write_rate,8000
  462. video_read_codec,H264
  463. video_read_rate,90000
  464. video_write_codec,H264
  465. video_write_rate,90000
  466. video_width,320
  467. video_height,240
  468. video_fps,10
  469. record_stereo,true
  470. dialed_extension,1010
  471.  
  472.  
  473.  
  474.  
  475.  
  476.  
  477.  
  478.  
  479.  
  480.  
  481. 2017-06-02 12:18:19.162809 [DEBUG] switch_cpp.cpp:1122 sofia/internal/1001@192.168.150.124 destroy/unlink session from object
  482. 2017-06-02 12:18:19.702834 [ERR] avformat.c:2131 Error while writing audio frame: Invalid argument
  483. 2017-06-02 12:18:19.722811 [ERR] avformat.c:2131 Error while writing audio frame: Invalid argument
  484. 2017-06-02 12:18:20.942833 [DEBUG] switch_ivr_bridge.c:825 sofia/internal/1010@192.168.150.103:5060 ending bridge by request from write function
  485. 2017-06-02 12:18:20.942833 [DEBUG] switch_ivr_bridge.c:848 Ending video thread.
  486. 2017-06-02 12:18:20.942833 [DEBUG] switch_ivr_bridge.c:906 Ending video thread.
  487. 2017-06-02 12:18:20.942833 [NOTICE] sofia.c:1079 Hangup sofia/internal/1010@192.168.150.103:5060 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING]
  488. 2017-06-02 12:18:20.942833 [DEBUG] switch_ivr_bridge.c:848 Ending video thread.
  489. 2017-06-02 12:18:20.942833 [DEBUG] switch_ivr_bridge.c:255 sofia/internal/1010@192.168.150.103:5060 video thread ended.
  490. 2017-06-02 12:18:20.942833 [DEBUG] switch_core_media.c:13744 sofia/internal/1010@192.168.150.103:5060 skip receive message [DISPLAY] (channel is hungup already)
  491. 2017-06-02 12:18:20.952807 [DEBUG] switch_ivr_bridge.c:917 BRIDGE THREAD DONE [sofia/internal/1010@192.168.150.103:5060]
  492. 2017-06-02 12:18:20.952807 [DEBUG] switch_core_state_machine.c:653 (sofia/internal/1010@192.168.150.103:5060) State EXCHANGE_MEDIA going to sleep
  493. 2017-06-02 12:18:20.952807 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1010@192.168.150.103:5060) Running State Change CS_HANGUP (Cur 2 Tot 233)
  494. 2017-06-02 12:18:20.952807 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/1010@192.168.150.103:5060) Callstate Change ACTIVE -> HANGUP
  495. 2017-06-02 12:18:20.952807 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1010@192.168.150.103:5060) State HANGUP
  496. 2017-06-02 12:18:20.952807 [DEBUG] mod_sofia.c:449 Channel sofia/internal/1010@192.168.150.103:5060 hanging up, cause: NORMAL_CLEARING
  497. 2017-06-02 12:18:20.952807 [DEBUG] switch_core_media.c:7104 sofia/internal/1010@192.168.150.103:5060 Video thread ended
  498. 2017-06-02 12:18:20.952807 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1010@192.168.150.103:5060 Standard HANGUP, cause: NORMAL_CLEARING
  499. 2017-06-02 12:18:20.952807 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1010@192.168.150.103:5060) State HANGUP going to sleep
  500. 2017-06-02 12:18:20.952807 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/1010@192.168.150.103:5060) State Change CS_HANGUP -> CS_REPORTING
  501. 2017-06-02 12:18:20.952807 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1010@192.168.150.103:5060) Running State Change CS_REPORTING (Cur 2 Tot 233)
  502. 2017-06-02 12:18:20.952807 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1010@192.168.150.103:5060) State REPORTING
  503. 2017-06-02 12:18:20.952807 [DEBUG] switch_core_state_machine.c:174 sofia/internal/1010@192.168.150.103:5060 Standard REPORTING, cause: NORMAL_CLEARING
  504. 2017-06-02 12:18:20.952807 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1010@192.168.150.103:5060) State REPORTING going to sleep
  505. 2017-06-02 12:18:20.952807 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/1010@192.168.150.103:5060) State Change CS_REPORTING -> CS_DESTROY
  506. 2017-06-02 12:18:20.952807 [DEBUG] switch_core_session.c:1712 Session 233 (sofia/internal/1010@192.168.150.103:5060) Locked, Waiting on external entities
  507. 2017-06-02 12:18:20.972809 [DEBUG] switch_ivr_bridge.c:255 sofia/internal/1001@192.168.150.124 video thread ended.
  508. 2017-06-02 12:18:20.972809 [DEBUG] switch_ivr_bridge.c:917 BRIDGE THREAD DONE [sofia/internal/1001@192.168.150.124]
  509. 2017-06-02 12:18:20.972809 [NOTICE] switch_ivr_bridge.c:1895 Hangup sofia/internal/1001@192.168.150.124 [CS_EXECUTE] [NORMAL_CLEARING]
  510. 2017-06-02 12:18:20.972809 [NOTICE] switch_core_session.c:1730 Session 233 (sofia/internal/1010@192.168.150.103:5060) Ended
  511. 2017-06-02 12:18:20.972809 [NOTICE] switch_core_session.c:1734 Close Channel sofia/internal/1010@192.168.150.103:5060 [CS_DESTROY]
  512. 2017-06-02 12:18:20.972809 [DEBUG] switch_core_session.c:2884 sofia/internal/1001@192.168.150.124 skip receive message [PHONE_EVENT] (channel is hungup already)
  513. 2017-06-02 12:18:20.972809 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/1001@192.168.150.124) State EXECUTE going to sleep
  514. 2017-06-02 12:18:20.972809 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1001@192.168.150.124) Running State Change CS_HANGUP (Cur 1 Tot 233)
  515. 2017-06-02 12:18:20.972809 [DEBUG] switch_ivr_async.c:1324 Stop recording file /var/www/html/fs/2017-06-02_12-18-16_5be54fde-a661-4390-9624-f603eed99e42.mp4
  516. 2017-06-02 12:18:20.972809 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/1010@192.168.150.103:5060) Running State Change CS_DESTROY (Cur 1 Tot 233)
  517. 2017-06-02 12:18:20.982807 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1010@192.168.150.103:5060) State DESTROY
  518. 2017-06-02 12:18:20.982807 [DEBUG] mod_sofia.c:354 sofia/internal/1010@192.168.150.103:5060 SOFIA DESTROY
  519. 2017-06-02 12:18:20.982807 [DEBUG] switch_core_state_machine.c:181 sofia/internal/1010@192.168.150.103:5060 Standard DESTROY
  520. 2017-06-02 12:18:20.982807 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1010@192.168.150.103:5060) State DESTROY going to sleep
  521. 2017-06-02 12:18:21.022806 [DEBUG] switch_core_media.c:7104 sofia/internal/1001@192.168.150.124 Video thread ended
  522. 2017-06-02 12:18:21.062806 [NOTICE] avformat.c:894 video thread done
  523. 2017-06-02 12:18:21.072804 [DEBUG] switch_ivr_async.c:1388 Channel is hung up
  524. 2017-06-02 12:18:21.072804 [DEBUG] switch_core_media_bug.c:1313 Removing BUG from sofia/internal/1001@192.168.150.124
  525. 2017-06-02 12:18:21.072804 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/1001@192.168.150.124) Callstate Change ACTIVE -> HANGUP
  526. 2017-06-02 12:18:21.072804 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1001@192.168.150.124) State HANGUP
  527. 2017-06-02 12:18:21.072804 [DEBUG] mod_sofia.c:443 sofia/internal/1001@192.168.150.124 Overriding SIP cause 480 with 200 from the other leg
  528. 2017-06-02 12:18:21.072804 [DEBUG] mod_sofia.c:449 Channel sofia/internal/1001@192.168.150.124 hanging up, cause: NORMAL_CLEARING
  529. 2017-06-02 12:18:21.072804 [DEBUG] mod_sofia.c:502 Sending BYE to sofia/internal/1001@192.168.150.124
  530. 2017-06-02 12:18:21.072804 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1001@192.168.150.124 Standard HANGUP, cause: NORMAL_CLEARING
  531. 2017-06-02 12:18:21.072804 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1001@192.168.150.124) State HANGUP going to sleep
  532. 2017-06-02 12:18:21.072804 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/1001@192.168.150.124) State Change CS_HANGUP -> CS_REPORTING
  533. 2017-06-02 12:18:21.072804 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1001@192.168.150.124) Running State Change CS_REPORTING (Cur 1 Tot 233)
  534. 2017-06-02 12:18:21.072804 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1001@192.168.150.124) State REPORTING
  535. 2017-06-02 12:18:21.072804 [DEBUG] switch_core_state_machine.c:174 sofia/internal/1001@192.168.150.124 Standard REPORTING, cause: NORMAL_CLEARING
  536. 2017-06-02 12:18:21.072804 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1001@192.168.150.124) State REPORTING going to sleep
  537. 2017-06-02 12:18:21.072804 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/1001@192.168.150.124) State Change CS_REPORTING -> CS_DESTROY
  538. 2017-06-02 12:18:21.072804 [DEBUG] switch_core_session.c:1712 Session 232 (sofia/internal/1001@192.168.150.124) Locked, Waiting on external entities
  539. 2017-06-02 12:18:21.072804 [NOTICE] switch_core_session.c:1730 Session 232 (sofia/internal/1001@192.168.150.124) Ended
  540. 2017-06-02 12:18:21.072804 [NOTICE] switch_core_session.c:1734 Close Channel sofia/internal/1001@192.168.150.124 [CS_DESTROY]
  541. 2017-06-02 12:18:21.072804 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/1001@192.168.150.124) Running State Change CS_DESTROY (Cur 0 Tot 233)
  542. 2017-06-02 12:18:21.072804 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1001@192.168.150.124) State DESTROY
  543. 2017-06-02 12:18:21.072804 [DEBUG] mod_sofia.c:354 sofia/internal/1001@192.168.150.124 SOFIA DESTROY
  544. 2017-06-02 12:18:21.072804 [DEBUG] switch_core_state_machine.c:181 sofia/internal/1001@192.168.150.124 Standard DESTROY
  545. 2017-06-02 12:18:21.072804 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1001@192.168.150.124) State DESTROY going to sleep
  546. freeswitch@fs1>

Reply to "Untitled"