From Flying Hummingbird, 6 Years ago, written in Plain Text.
- view diff
Embed
  1. 2018-03-21 09:57:02.939258 [NOTICE] mod_logfile.c:192 New log started.
  2. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.839258 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/1001@192.168.150.3 [a0ca0a7f-9131-4c40-96e8-987fede99823]
  3. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.839258 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1001@192.168.150.3) Running State Change CS_NEW (Cur 1 Tot 68)
  4. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.839258 [DEBUG] sofia.c:10072 sofia/internal/1001@192.168.150.3 receiving invite from 192.168.150.38:61063 version: 1.9.0 git c093b2d 2018-03-20 14:32:52Z 64bit
  5. 2018-03-21 09:57:06.839258 [DEBUG] sofia_reg.c:1788 Send challenge for [1000@192.168.150.3]
  6. 2018-03-21 09:57:06.839258 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'internal' for [1000@192.168.150.3] from ip 192.168.150.38
  7. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.839258 [DEBUG] switch_core_state_machine.c:603 (sofia/internal/1001@192.168.150.3) State NEW
  8. 2018-03-21 09:57:06.839258 [DEBUG] sofia.c:2405 detaching session a0ca0a7f-9131-4c40-96e8-987fede99823
  9. 2018-03-21 09:57:06.889256 [DEBUG] sofia.c:2514 Re-attaching to session a0ca0a7f-9131-4c40-96e8-987fede99823
  10. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [DEBUG] sofia.c:10072 sofia/internal/1001@192.168.150.3 receiving invite from 192.168.150.38:61063 version: 1.9.0 git c093b2d 2018-03-20 14:32:52Z 64bit
  11. 2018-03-21 09:57:06.899228 [DEBUG] sofia_reg.c:3162 event_add_header -> 'record_stereo' = 'true'
  12. 2018-03-21 09:57:06.899228 [DEBUG] sofia_reg.c:3162 event_add_header -> 'default_areacode' = '918'
  13. 2018-03-21 09:57:06.899228 [DEBUG] sofia_reg.c:3162 event_add_header -> 'transfer_fallback_extension' = 'operator'
  14. 2018-03-21 09:57:06.899228 [DEBUG] sofia_reg.c:3162 event_add_header -> 'toll_allow' = 'domestic,international,local'
  15. 2018-03-21 09:57:06.899228 [DEBUG] sofia_reg.c:3162 event_add_header -> 'accountcode' = '1001'
  16. 2018-03-21 09:57:06.899228 [DEBUG] sofia_reg.c:3162 event_add_header -> 'user_context' = 'default'
  17. 2018-03-21 09:57:06.899228 [DEBUG] sofia_reg.c:3162 event_add_header -> 'outbound_caller_id_name' = 'FreeSWITCH'
  18. 2018-03-21 09:57:06.899228 [DEBUG] sofia_reg.c:3162 event_add_header -> 'outbound_caller_id_number' = '0000000000'
  19. 2018-03-21 09:57:06.899228 [DEBUG] sofia_reg.c:3162 event_add_header -> 'callgroup' = 'sales'
  20. 2018-03-21 09:57:06.899228 [DEBUG] sofia_reg.c:3162 event_add_header -> 'user_1001_chan_var' = 'value_1001'
  21. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [DEBUG] sofia.c:7283 Channel sofia/internal/1001@192.168.150.3 entering state [received][100]
  22. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [DEBUG] sofia.c:7293 Remote SDP:
  23. a0ca0a7f-9131-4c40-96e8-987fede99823 v=0
  24. a0ca0a7f-9131-4c40-96e8-987fede99823 o=- 13166114225392269 1 IN IP4 192.168.150.38
  25. a0ca0a7f-9131-4c40-96e8-987fede99823 s=Bria 5 release 5.0.3 stamp 88308
  26. a0ca0a7f-9131-4c40-96e8-987fede99823 c=IN IP4 192.168.150.38
  27. a0ca0a7f-9131-4c40-96e8-987fede99823 t=0 0
  28. a0ca0a7f-9131-4c40-96e8-987fede99823 m=audio 51268 RTP/AVP 9 8 85 18 120 0 84 121 122 123 3 101
  29. a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtpmap:85 speex/8000
  30. a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtpmap:18 G729/8000
  31. a0ca0a7f-9131-4c40-96e8-987fede99823 a=fmtp:18 annexb=yes
  32. a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtpmap:120 opus/48000/2
  33. a0ca0a7f-9131-4c40-96e8-987fede99823 a=fmtp:120 useinbandfec=1; usedtx=1; maxaveragebitrate=64000
  34. a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtpmap:84 speex/16000
  35. a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtpmap:121 SILK/8000
  36. a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtpmap:122 SILK/16000
  37. a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtpmap:123 SILK/24000
  38. a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtpmap:101 telephone-event/8000
  39. a0ca0a7f-9131-4c40-96e8-987fede99823 a=fmtp:101 0-15
  40. a0ca0a7f-9131-4c40-96e8-987fede99823
  41. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [DEBUG] sofia.c:7687 (sofia/internal/1001@192.168.150.3) State Change CS_NEW -> CS_INIT
  42. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1001@192.168.150.3) Running State Change CS_INIT (Cur 1 Tot 68)
  43. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1001@192.168.150.3) State INIT
  44. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [DEBUG] mod_sofia.c:93 sofia/internal/1001@192.168.150.3 SOFIA INIT
  45. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1001@192.168.150.3 Standard INIT
  46. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1001@192.168.150.3) State Change CS_INIT -> CS_ROUTING
  47. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1001@192.168.150.3) State INIT going to sleep
  48. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1001@192.168.150.3) Running State Change CS_ROUTING (Cur 1 Tot 68)
  49. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [DEBUG] switch_channel.c:2249 (sofia/internal/1001@192.168.150.3) Callstate Change DOWN -> RINGING
  50. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1001@192.168.150.3) State ROUTING
  51. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [DEBUG] mod_sofia.c:154 sofia/internal/1001@192.168.150.3 SOFIA ROUTING
  52. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [DEBUG] switch_core_state_machine.c:236 sofia/internal/1001@192.168.150.3 Standard ROUTING
  53. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [INFO] mod_dialplan_xml.c:637 Processing 1001 <1001>->1000 in context default
  54. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->record silence energy] continue=false
  55. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [record silence energy] ${destination_number}(1000) =~ /^311$/ break=on-false
  56. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->flowroute.com] continue=false
  57. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [flowroute.com] destination_number(1000) =~ /^f?3?\+?(1?\d{10})$/ break=on-false
  58. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->telnyx] continue=false
  59. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [telnyx] destination_number(1000) =~ /^t?8?\+?(1?\d{10})$/ break=on-false
  60. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->domestic.twilio.short] continue=false
  61. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [domestic.twilio.short] destination_number(1000) =~ /^t?w?(1?\d{10})$/ break=on-false
  62. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->park] continue=false
  63. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [park] destination_number(1000) =~ /^park|7275$/ break=on-false
  64. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->delay_echo] continue=false
  65. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [delay_echo] destination_number(1000) =~ /^delay_echo|33246$/ break=on-false
  66. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->echo] continue=false
  67. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [echo] destination_number(1000) =~ /^echo|3246$/ break=on-false
  68. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->shout test] continue=false
  69. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [shout test] destination_number(1000) =~ /^shout|74688$/ break=on-false
  70. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->watson_ws TTS test] continue=false
  71. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [watson_ws TTS test] destination_number(1000) =~ /^watson_ws|980$/ break=on-false
  72. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->watson ASR test] continue=false
  73. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [watson ASR test] destination_number(1000) =~ /^watson|981$/ break=on-false
  74. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->call center customer] continue=false
  75. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [call center customer] destination_number(1000) =~ /996/ break=on-false
  76. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->call center agent stuff] continue=false
  77. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [call center agent stuff] destination_number(1000) =~ /^(997)$/ break=on-false
  78. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->call center login] continue=false
  79. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [call center login] destination_number(1000) =~ /^agent-login|998$/ break=on-false
  80. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->call center logout] continue=false
  81. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [call center logout] destination_number(1000) =~ /^agent-logout|999$/ break=on-false
  82. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->gentones] continue=false
  83. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [gentones] destination_number(1000) =~ /^(gentones|1998)$/ break=on-false
  84. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->no_more_funds] continue=false
  85. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [no_more_funds] destination_number(1000) =~ /^(no_more_funds)$/ break=on-false
  86. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->add_funds] continue=false
  87. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [add_funds] destination_number(1000) =~ /^(add_funds)$/ break=on-false
  88. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->test-json-cdr] continue=false
  89. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [test-json-cdr] destination_number(1000) =~ /^(3533)$/ break=on-false
  90. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->g722 EncoreGroup test] continue=false
  91. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [g722 EncoreGroup test] destination_number(1000) =~ /^1999$/ break=on-false
  92. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->applicant interview] continue=false
  93. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [applicant interview] destination_number(1000) =~ /^2010$/ break=on-false
  94. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->8x8 test] continue=false
  95. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [8x8 test] destination_number(1000) =~ /^2001$/ break=on-false
  96. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->ascii YY ZZZ - to play ascii wav files] continue=false
  97. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [ascii YY ZZZ - to play ascii wav files] destination_number(1000) =~ /^ascii (\d{2}|\d{3}) (\d{2}|\d{3})$/ break=on-false
  98. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->speak something] continue=false
  99. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [speak something] destination_number(1000) =~ /^speakthis$/ break=on-false
  100. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->say something] continue=false
  101. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [say something] destination_number(1000) =~ /^saythis$/ break=on-false
  102. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->phrase something] continue=false
  103. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [phrase something] destination_number(1000) =~ /^phrasethis$/ break=on-false
  104. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->P-Asserted-Identity] continue=false
  105. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [P-Asserted-Identity] destination_number(1000) =~ /pidtest/ break=on-false
  106. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->channel variable test] continue=false
  107. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [channel variable test] destination_number(1000) =~ /^1020$/ break=on-false
  108. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->bridge simultaneous blegs - ringall group] continue=false
  109. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [bridge simultaneous blegs - ringall group] destination_number(1000) =~ /^1021$/ break=on-false
  110. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->bridge sequential blegs - hunt/round-robin group] continue=false
  111. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [bridge sequential blegs - hunt/round-robin group] destination_number(1000) =~ /^1022$/ break=on-false
  112. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->bridge enterprise blegs] continue=false
  113. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [bridge enterprise blegs] destination_number(1000) =~ /^1023$/ break=on-false
  114. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->group_test] continue=false
  115. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [group_test] destination_number(1000) =~ /^99$/ break=on-false
  116. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->sales] continue=false
  117. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [sales] destination_number(1000) =~ /sales|200/ break=on-false
  118. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->play_and_get_digits example] continue=false
  119. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [play_and_get_digits example] destination_number(1000) =~ /^(1888)$/ break=on-false
  120. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->notworking] continue=false
  121. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [notworking] destination_number(1000) =~ /^996$/ break=on-false
  122. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->working] continue=false
  123. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [working] destination_number(1000) =~ /^997$/ break=on-false
  124. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->local stream] continue=false
  125. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [local stream] destination_number(1000) =~ /^787|local_stream$/ break=on-false
  126. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->fifo agent] continue=false
  127. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [fifo agent] destination_number(1000) =~ /^777$/ break=on-false
  128. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->fifo customer] continue=false
  129. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [fifo customer] destination_number(1000) =~ /^(778)$/ break=on-false
  130. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->cryptconf.com] continue=false
  131. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [cryptconf.com] destination_number(1000) =~ /^9(10[01][0-9])$/ break=on-false
  132. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->perl_test] continue=false
  133. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [perl_test] destination_number(1000) =~ /^(595)$/ break=on-false
  134. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->test flac play] continue=false
  135. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [test flac play] destination_number(1000) =~ /^(596)$/ break=on-false
  136. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->test flac record] continue=false
  137. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [test flac record] destination_number(1000) =~ /^(597)$/ break=on-false
  138. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->test lua] continue=false
  139. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [test lua] destination_number(1000) =~ /^(598)$/ break=on-false
  140. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->123_screen] continue=false
  141. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [123_screen] destination_number(1000) =~ /^(3600)$/ break=on-false
  142. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->conf_bridger] continue=false
  143. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [conf_bridger] destination_number(1000) =~ /^599$/ break=on-false
  144. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->cdquality_stereo_conferences] continue=false
  145. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [cdquality_stereo_conferences] destination_number(1000) =~ /^599-screen$/ break=on-false
  146. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->unloop] continue=false
  147. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
  148. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
  149. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->tod_example] continue=true
  150. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Date/Time Match (PASS) [tod_example] break=on-false
  151. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Action set(open=true)
  152. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->holiday_example] continue=true
  153. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Date/TimeMatch (FAIL) [holiday_example] break=on-false
  154. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->global-intercept] continue=false
  155. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [global-intercept] destination_number(1000) =~ /^886$/ break=on-false
  156. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->group-intercept] continue=false
  157. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [group-intercept] destination_number(1000) =~ /^\*8$/ break=on-false
  158. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->intercept-ext] continue=false
  159. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [intercept-ext] destination_number(1000) =~ /^\*\*(\d+)$/ break=on-false
  160. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->redial] continue=false
  161. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [redial] destination_number(1000) =~ /^(redial|870)$/ break=on-false
  162. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->global] continue=true
  163. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [global] ${call_debug}(false) =~ /^true$/ break=never
  164. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [global] ${default_password}(j0sh3b0sh) =~ /^1234$/ break=never
  165. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 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
  166. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [global] ${rtp_has_crypto}() =~ /^((sip:dtls:)?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
  167. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (PASS) [global] ${endpoint_disposition}(DELAYED NEGOTIATION) =~ /^(DELAYED NEGOTIATION)/ break=on-false
  168. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [global] ${switch_r_sdp}(v=0
  169. a0ca0a7f-9131-4c40-96e8-987fede99823 o=- 13166114225392269 1 IN IP4 192.168.150.38
  170. a0ca0a7f-9131-4c40-96e8-987fede99823 s=Bria 5 release 5.0.3 stamp 88308
  171. a0ca0a7f-9131-4c40-96e8-987fede99823 c=IN IP4 192.168.150.38
  172. a0ca0a7f-9131-4c40-96e8-987fede99823 t=0 0
  173. a0ca0a7f-9131-4c40-96e8-987fede99823 m=audio 51268 RTP/AVP 9 8 85 18 120 0 84 121 122 123 3 101
  174. a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtpmap:85 speex/8000
  175. a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtpmap:18 G729/8000
  176. a0ca0a7f-9131-4c40-96e8-987fede99823 a=fmtp:18 annexb=yes
  177. a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtpmap:120 opus/48000/2
  178. a0ca0a7f-9131-4c40-96e8-987fede99823 a=fmtp:120 useinbandfec=1; usedtx=1; maxaveragebitrate=64000
  179. a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtpmap:84 speex/16000
  180. a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtpmap:121 SILK/8000
  181. a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtpmap:122 SILK/16000
  182. a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtpmap:123 SILK/24000
  183. a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtpmap:101 telephone-event/8000
  184. a0ca0a7f-9131-4c40-96e8-987fede99823 a=fmtp:101 0-15
  185. a0ca0a7f-9131-4c40-96e8-987fede99823 ) =~ /(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)/ break=never
  186. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Absolute Condition [global]
  187. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Action hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid})
  188. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
  189. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Action hash(insert/${domain_name}-last_dial/global/${uuid})
  190. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
  191. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->snom-demo-2] continue=false
  192. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [snom-demo-2] destination_number(1000) =~ /^9001$/ break=on-false
  193. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->snom-demo-1] continue=false
  194. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [snom-demo-1] destination_number(1000) =~ /^9000$/ break=on-false
  195. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->eavesdrop] continue=false
  196. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [eavesdrop] destination_number(1000) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false
  197. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->eavesdrop] continue=false
  198. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [eavesdrop] destination_number(1000) =~ /^779$/ break=on-false
  199. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->call_return] continue=false
  200. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [call_return] destination_number(1000) =~ /^\*69$|^869$|^lcr$/ break=on-false
  201. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->del-group] continue=false
  202. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [del-group] destination_number(1000) =~ /^80(\d{2})$/ break=on-false
  203. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->add-group] continue=false
  204. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [add-group] destination_number(1000) =~ /^81(\d{2})$/ break=on-false
  205. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->call-group-simo] continue=false
  206. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [call-group-simo] destination_number(1000) =~ /^82(\d{2})$/ break=on-false
  207. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->call-group-order] continue=false
  208. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [call-group-order] destination_number(1000) =~ /^83(\d{2})$/ break=on-false
  209. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->extension-intercom] continue=false
  210. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [extension-intercom] destination_number(1000) =~ /^8(10[01][0-9])$/ break=on-false
  211. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->Local_Extension] continue=false
  212. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (PASS) [Local_Extension] destination_number(1000) =~ /^(10[01][0-9])$/ break=on-false
  213. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Action export(dialed_extension=1000)
  214. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Action bind_meta_app(1 b s execute_extension::dx XML features)
  215. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Action bind_meta_app(2 b s record_session::/usr/local/freeswitch/recordings/${caller_id_number}.${strftime(%Y-%m-%d-%H-%M-%S)}.wav)
  216. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Action bind_meta_app(3 b s execute_extension::cf XML features)
  217. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Action bind_meta_app(4 b s execute_extension::att_xfer XML features)
  218. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Action bind_meta_app(5 ab s playback::${sounds_dir}/joshebosh/Answering_Machine.wav)
  219. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Action pre_answer()
  220. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Action set(ringback=${us-ring})
  221. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Action set(transfer_ringback=/usr/local/freeswitch/sounds/joshebosh/Tomtoms.wav)
  222. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Action set(call_timeout=30)
  223. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Action set(hangup_after_bridge=true)
  224. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Action set(continue_on_fail=false)
  225. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Action hash(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_number})
  226. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Action hash(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid})
  227. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Action set(called_party_callgroup=${user_data(${dialed_extension}@${domain_name} var callgroup)})
  228. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Action hash(insert/${domain_name}-last_dial_ext/${called_party_callgroup}/${uuid})
  229. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Action hash(insert/${domain_name}-last_dial_ext/global/${uuid})
  230. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Action hash(insert/${domain_name}-last_dial/${called_party_callgroup}/${uuid})
  231. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Action set(record_concat_video=true)
  232. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Action set(record_filename=/var/www/html/fs/${strftime(%Y-%m-%d-%H-%M-%S)}_${uuid}.mp4) INLINE
  233. a0ca0a7f-9131-4c40-96e8-987fede99823 EXECUTE sofia/internal/1001@192.168.150.3 set(record_filename=/var/www/html/fs/2018-03-21-09-57-06_a0ca0a7f-9131-4c40-96e8-987fede99823.mp4)
  234. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [DEBUG] mod_dptools.c:1588 SET sofia/internal/1001@192.168.150.3 [record_filename]=[/var/www/html/fs/2018-03-21-09-57-06_a0ca0a7f-9131-4c40-96e8-987fede99823.mp4]
  235. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Action set(RECORD_MIN_SEC=2)
  236. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Action set(RECORD_STEREO=true)
  237. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Action bridge(user/${dialed_extension}@${domain_name})
  238. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Action hangup()
  239. a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Action bridge(loopback/app=voicemail:default ${domain_name} ${dialed_extension})
  240. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/1001@192.168.150.3) State Change CS_ROUTING -> CS_EXECUTE
  241. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1001@192.168.150.3) State ROUTING going to sleep
  242. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1001@192.168.150.3) Running State Change CS_EXECUTE (Cur 1 Tot 68)
  243. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/1001@192.168.150.3) State EXECUTE
  244. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [DEBUG] mod_sofia.c:209 sofia/internal/1001@192.168.150.3 SOFIA EXECUTE
  245. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [DEBUG] switch_core_state_machine.c:328 sofia/internal/1001@192.168.150.3 Standard EXECUTE
  246. a0ca0a7f-9131-4c40-96e8-987fede99823 EXECUTE sofia/internal/1001@192.168.150.3 set(open=true)
  247. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [DEBUG] mod_dptools.c:1588 SET sofia/internal/1001@192.168.150.3 [open]=[true]
  248. a0ca0a7f-9131-4c40-96e8-987fede99823 EXECUTE sofia/internal/1001@192.168.150.3 hash(insert/192.168.150.3-spymap/1001/a0ca0a7f-9131-4c40-96e8-987fede99823)
  249. a0ca0a7f-9131-4c40-96e8-987fede99823 EXECUTE sofia/internal/1001@192.168.150.3 hash(insert/192.168.150.3-last_dial/1001/1000)
  250. a0ca0a7f-9131-4c40-96e8-987fede99823 EXECUTE sofia/internal/1001@192.168.150.3 hash(insert/192.168.150.3-last_dial/global/a0ca0a7f-9131-4c40-96e8-987fede99823)
  251. a0ca0a7f-9131-4c40-96e8-987fede99823 EXECUTE sofia/internal/1001@192.168.150.3 export(RFC2822_DATE=Wed, 21 Mar 2018 09:57:06 -0400)
  252. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [RFC2822_DATE]=[Wed, 21 Mar 2018 09:57:06 -0400]
  253. a0ca0a7f-9131-4c40-96e8-987fede99823 EXECUTE sofia/internal/1001@192.168.150.3 export(dialed_extension=1000)
  254. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [dialed_extension]=[1000]
  255. a0ca0a7f-9131-4c40-96e8-987fede99823 EXECUTE sofia/internal/1001@192.168.150.3 bind_meta_app(1 b s execute_extension::dx XML features)
  256. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [INFO] switch_ivr_async.c:4273 Bound B-Leg: *1 execute_extension::dx XML features
  257. a0ca0a7f-9131-4c40-96e8-987fede99823 EXECUTE sofia/internal/1001@192.168.150.3 bind_meta_app(2 b s record_session::/usr/local/freeswitch/recordings/1001.2018-03-21-09-57-06.wav)
  258. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [INFO] switch_ivr_async.c:4273 Bound B-Leg: *2 record_session::/usr/local/freeswitch/recordings/1001.2018-03-21-09-57-06.wav
  259. a0ca0a7f-9131-4c40-96e8-987fede99823 EXECUTE sofia/internal/1001@192.168.150.3 bind_meta_app(3 b s execute_extension::cf XML features)
  260. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [INFO] switch_ivr_async.c:4273 Bound B-Leg: *3 execute_extension::cf XML features
  261. a0ca0a7f-9131-4c40-96e8-987fede99823 EXECUTE sofia/internal/1001@192.168.150.3 bind_meta_app(4 b s execute_extension::att_xfer XML features)
  262. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [INFO] switch_ivr_async.c:4273 Bound B-Leg: *4 execute_extension::att_xfer XML features
  263. a0ca0a7f-9131-4c40-96e8-987fede99823 EXECUTE sofia/internal/1001@192.168.150.3 bind_meta_app(5 ab s playback::/usr/local/freeswitch/sounds/joshebosh/Answering_Machine.wav)
  264. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [INFO] switch_ivr_async.c:4265 Bound A-Leg: *5 playback::/usr/local/freeswitch/sounds/joshebosh/Answering_Machine.wav
  265. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [INFO] switch_ivr_async.c:4273 Bound B-Leg: *5 playback::/usr/local/freeswitch/sounds/joshebosh/Answering_Machine.wav
  266. a0ca0a7f-9131-4c40-96e8-987fede99823 EXECUTE sofia/internal/1001@192.168.150.3 pre_answer()
  267. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [INFO] mod_dptools.c:1395 Sending early media
  268. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [G722:9:8000:20:64000:1]/[opus:116:48000:20:0:1]
  269. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  270. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5507 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match
  271. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  272. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  273. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1]
  274. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  275. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  276. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  277. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5507 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
  278. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [speex:85:8000:20:0:1]/[opus:116:48000:20:0:1]
  279. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [speex:85:8000:20:0:1]/[G722:9:8000:20:64000:1]
  280. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [speex:85:8000:20:0:1]/[PCMU:0:8000:20:64000:1]
  281. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [speex:85:8000:20:0:1]/[PCMA:8:8000:20:64000:1]
  282. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [G729:18:8000:20:8000:1]/[opus:116:48000:20:0:1]
  283. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [G729:18:8000:20:8000:1]/[G722:9:8000:20:64000:1]
  284. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
  285. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
  286. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [opus:120:48000:20:0:1]/[opus:116:48000:20:0:1]
  287. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5507 Audio Codec Compare [opus:116:48000:20:0:1] ++++ is saved as a match
  288. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [opus:120:48000:20:0:1]/[G722:9:8000:20:64000:1]
  289. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [opus:120:48000:20:0:1]/[PCMU:0:8000:20:64000:1]
  290. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [opus:120:48000:20:0:1]/[PCMA:8:8000:20:64000:1]
  291. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1]
  292. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  293. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  294. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5507 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
  295. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  296. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [speex:84:16000:20:0:1]/[opus:116:48000:20:0:1]
  297. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [speex:84:16000:20:0:1]/[G722:9:8000:20:64000:1]
  298. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [speex:84:16000:20:0:1]/[PCMU:0:8000:20:64000:1]
  299. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [speex:84:16000:20:0:1]/[PCMA:8:8000:20:64000:1]
  300. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [SILK:121:8000:20:0:1]/[opus:116:48000:20:0:1]
  301. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [SILK:121:8000:20:0:1]/[G722:9:8000:20:64000:1]
  302. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [SILK:121:8000:20:0:1]/[PCMU:0:8000:20:64000:1]
  303. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [SILK:121:8000:20:0:1]/[PCMA:8:8000:20:64000:1]
  304. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [SILK:122:16000:20:0:1]/[opus:116:48000:20:0:1]
  305. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [SILK:122:16000:20:0:1]/[G722:9:8000:20:64000:1]
  306. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [SILK:122:16000:20:0:1]/[PCMU:0:8000:20:64000:1]
  307. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [SILK:122:16000:20:0:1]/[PCMA:8:8000:20:64000:1]
  308. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [SILK:123:24000:20:0:1]/[opus:116:48000:20:0:1]
  309. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [SILK:123:24000:20:0:1]/[G722:9:8000:20:64000:1]
  310. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [SILK:123:24000:20:0:1]/[PCMU:0:8000:20:64000:1]
  311. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [SILK:123:24000:20:0:1]/[PCMA:8:8000:20:64000:1]
  312. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [GSM:3:8000:20:13200:1]/[opus:116:48000:20:0:1]
  313. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [GSM:3:8000:20:13200:1]/[G722:9:8000:20:64000:1]
  314. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMU:0:8000:20:64000:1]
  315. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMA:8:8000:20:64000:1]
  316. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5368 Set telephone-event payload to 101@8000
  317. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:3767 Set Codec sofia/internal/1001@192.168.150.3 G722/8000 20 ms 160 samples 64000 bits 1 channels
  318. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_codec.c:111 sofia/internal/1001@192.168.150.3 Original read codec set to G722:9
  319. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5711 Set telephone-event payload to 101@8000
  320. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5769 sofia/internal/1001@192.168.150.3 Set 2833 dtmf send payload to 101 recv payload to 101
  321. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:8486 AUDIO RTP [sofia/internal/1001@192.168.150.3] 192.168.150.3 port 16422 -> 192.168.150.38 port 51268 codec: 9 ms: 20
  322. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_rtp.c:4276 Starting timer [soft] 160 bytes per 20ms
  323. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:8790 sofia/internal/1001@192.168.150.3 Set 2833 dtmf send payload to 101
  324. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:8797 sofia/internal/1001@192.168.150.3 Set 2833 dtmf receive payload to 101
  325. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:8820 sofia/internal/1001@192.168.150.3 Set rtp dtmf delay to 40
  326. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [NOTICE] sofia_media.c:92 Pre-Answer sofia/internal/1001@192.168.150.3!
  327. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_channel.c:3482 (sofia/internal/1001@192.168.150.3) Callstate Change RINGING -> EARLY
  328. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:8469 Audio params are unchanged for sofia/internal/1001@192.168.150.3.
  329. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] mod_sofia.c:2514 Ring SDP:
  330. a0ca0a7f-9131-4c40-96e8-987fede99823 v=0
  331. a0ca0a7f-9131-4c40-96e8-987fede99823 o=FreeSWITCH 1521624204 1521624205 IN IP4 192.168.150.3
  332. a0ca0a7f-9131-4c40-96e8-987fede99823 s=FreeSWITCH
  333. a0ca0a7f-9131-4c40-96e8-987fede99823 c=IN IP4 192.168.150.3
  334. a0ca0a7f-9131-4c40-96e8-987fede99823 t=0 0
  335. a0ca0a7f-9131-4c40-96e8-987fede99823 m=audio 16422 RTP/AVP 9 101
  336. a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtpmap:9 G722/8000
  337. a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtpmap:101 telephone-event/8000
  338. a0ca0a7f-9131-4c40-96e8-987fede99823 a=fmtp:101 0-16
  339. a0ca0a7f-9131-4c40-96e8-987fede99823 a=ptime:20
  340. a0ca0a7f-9131-4c40-96e8-987fede99823 a=sendrecv
  341. a0ca0a7f-9131-4c40-96e8-987fede99823
  342. a0ca0a7f-9131-4c40-96e8-987fede99823 EXECUTE sofia/internal/1001@192.168.150.3 set(ringback=%(2000,4000,440,480))
  343. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] sofia.c:7283 Channel sofia/internal/1001@192.168.150.3 entering state [early][183]
  344. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] mod_dptools.c:1588 SET sofia/internal/1001@192.168.150.3 [ringback]=[%(2000,4000,440,480)]
  345. a0ca0a7f-9131-4c40-96e8-987fede99823 EXECUTE sofia/internal/1001@192.168.150.3 set(transfer_ringback=/usr/local/freeswitch/sounds/joshebosh/Tomtoms.wav)
  346. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] mod_dptools.c:1588 SET sofia/internal/1001@192.168.150.3 [transfer_ringback]=[/usr/local/freeswitch/sounds/joshebosh/Tomtoms.wav]
  347. a0ca0a7f-9131-4c40-96e8-987fede99823 EXECUTE sofia/internal/1001@192.168.150.3 set(call_timeout=30)
  348. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] mod_dptools.c:1588 SET sofia/internal/1001@192.168.150.3 [call_timeout]=[30]
  349. a0ca0a7f-9131-4c40-96e8-987fede99823 EXECUTE sofia/internal/1001@192.168.150.3 set(hangup_after_bridge=true)
  350. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] mod_dptools.c:1588 SET sofia/internal/1001@192.168.150.3 [hangup_after_bridge]=[true]
  351. a0ca0a7f-9131-4c40-96e8-987fede99823 EXECUTE sofia/internal/1001@192.168.150.3 set(continue_on_fail=false)
  352. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] mod_dptools.c:1588 SET sofia/internal/1001@192.168.150.3 [continue_on_fail]=[false]
  353. a0ca0a7f-9131-4c40-96e8-987fede99823 EXECUTE sofia/internal/1001@192.168.150.3 hash(insert/192.168.150.3-call_return/1000/1001)
  354. a0ca0a7f-9131-4c40-96e8-987fede99823 EXECUTE sofia/internal/1001@192.168.150.3 hash(insert/192.168.150.3-last_dial_ext/1000/a0ca0a7f-9131-4c40-96e8-987fede99823)
  355. a0ca0a7f-9131-4c40-96e8-987fede99823 EXECUTE sofia/internal/1001@192.168.150.3 set(called_party_callgroup=sales)
  356. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] mod_dptools.c:1588 SET sofia/internal/1001@192.168.150.3 [called_party_callgroup]=[sales]
  357. a0ca0a7f-9131-4c40-96e8-987fede99823 EXECUTE sofia/internal/1001@192.168.150.3 hash(insert/192.168.150.3-last_dial_ext/sales/a0ca0a7f-9131-4c40-96e8-987fede99823)
  358. a0ca0a7f-9131-4c40-96e8-987fede99823 EXECUTE sofia/internal/1001@192.168.150.3 hash(insert/192.168.150.3-last_dial_ext/global/a0ca0a7f-9131-4c40-96e8-987fede99823)
  359. a0ca0a7f-9131-4c40-96e8-987fede99823 EXECUTE sofia/internal/1001@192.168.150.3 hash(insert/192.168.150.3-last_dial/sales/a0ca0a7f-9131-4c40-96e8-987fede99823)
  360. a0ca0a7f-9131-4c40-96e8-987fede99823 EXECUTE sofia/internal/1001@192.168.150.3 set(record_concat_video=true)
  361. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] mod_dptools.c:1588 SET sofia/internal/1001@192.168.150.3 [record_concat_video]=[true]
  362. a0ca0a7f-9131-4c40-96e8-987fede99823 EXECUTE sofia/internal/1001@192.168.150.3 set(RECORD_MIN_SEC=2)
  363. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] mod_dptools.c:1588 SET sofia/internal/1001@192.168.150.3 [RECORD_MIN_SEC]=[2]
  364. a0ca0a7f-9131-4c40-96e8-987fede99823 EXECUTE sofia/internal/1001@192.168.150.3 set(RECORD_STEREO=true)
  365. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.919229 [DEBUG] mod_dptools.c:1588 SET sofia/internal/1001@192.168.150.3 [RECORD_STEREO]=[true]
  366. a0ca0a7f-9131-4c40-96e8-987fede99823 EXECUTE sofia/internal/1001@192.168.150.3 bridge(user/1000@192.168.150.3)
  367. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.919229 [DEBUG] switch_channel.c:1250 sofia/internal/1001@192.168.150.3 EXPORTING[export_vars] [RFC2822_DATE]=[Wed, 21 Mar 2018 09:57:06 -0400] to event
  368. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.919229 [DEBUG] switch_channel.c:1250 sofia/internal/1001@192.168.150.3 EXPORTING[export_vars] [dialed_extension]=[1000] to event
  369. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.919229 [DEBUG] switch_ivr_originate.c:2159 Parsing global variables
  370. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.919229 [DEBUG] switch_channel.c:1250 sofia/internal/1001@192.168.150.3 EXPORTING[export_vars] [RFC2822_DATE]=[Wed, 21 Mar 2018 09:57:06 -0400] to event
  371. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.919229 [DEBUG] switch_channel.c:1250 sofia/internal/1001@192.168.150.3 EXPORTING[export_vars] [dialed_extension]=[1000] to event
  372. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.919229 [DEBUG] switch_ivr_originate.c:2159 Parsing global variables
  373. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:06.919229 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/1000@192.168.150.44:46118 [1a8b93af-e2fa-4189-a0e2-c6a94f451f45]
  374. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:06.919229 [DEBUG] mod_sofia.c:5028 (sofia/internal/1000@192.168.150.44:46118) State Change CS_NEW -> CS_INIT
  375. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@192.168.150.44:46118) Running State Change CS_INIT (Cur 2 Tot 69)
  376. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1000@192.168.150.44:46118) State INIT
  377. cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:06.919229 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/1000@192.168.1.131:46140 [cff610de-5d42-482d-877c-c2748850a999]
  378. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:06.919229 [DEBUG] mod_sofia.c:93 sofia/internal/1000@192.168.150.44:46118 SOFIA INIT
  379. cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:06.919229 [DEBUG] mod_sofia.c:5028 (sofia/internal/1000@192.168.1.131:46140) State Change CS_NEW -> CS_INIT
  380. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:06.919229 [DEBUG] sofia_glue.c:1299 sofia/internal/1000@192.168.150.44:46118 sending invite version: 1.9.0 git c093b2d 2018-03-20 14:32:52Z 64bit
  381. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 Local SDP:
  382. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 v=0
  383. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 o=FreeSWITCH 1521624232 1521624233 IN IP4 192.168.150.3
  384. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 s=FreeSWITCH
  385. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 c=IN IP4 192.168.150.3
  386. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 t=0 0
  387. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 m=audio 16394 RTP/AVP 9 102 0 8
  388. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 a=rtpmap:9 G722/8000
  389. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 a=rtpmap:102 opus/48000/2
  390. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 a=fmtp:102 useinbandfec=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40
  391. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 a=rtpmap:0 PCMU/8000
  392. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 a=rtpmap:8 PCMA/8000
  393. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 a=ptime:20
  394. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 a=sendrecv
  395. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 m=video 16396 RTP/AVP 103 104
  396. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 b=AS:1024
  397. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 a=rtpmap:103 VP8/90000
  398. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 a=rtpmap:104 H264/90000
  399. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 a=sendrecv
  400. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 a=rtcp-fb:103 ccm fir
  401. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 a=rtcp-fb:103 ccm tmmbr
  402. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 a=rtcp-fb:103 nack
  403. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 a=rtcp-fb:103 nack pli
  404. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 a=rtcp-fb:104 ccm fir
  405. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 a=rtcp-fb:104 ccm tmmbr
  406. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 a=rtcp-fb:104 nack
  407. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 a=rtcp-fb:104 nack pli
  408. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45
  409. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1000@192.168.150.44:46118 Standard INIT
  410. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1000@192.168.150.44:46118) State Change CS_INIT -> CS_ROUTING
  411. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1000@192.168.150.44:46118) State INIT going to sleep
  412. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@192.168.150.44:46118) Running State Change CS_ROUTING (Cur 3 Tot 70)
  413. cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@192.168.1.131:46140) Running State Change CS_INIT (Cur 3 Tot 70)
  414. cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1000@192.168.1.131:46140) State INIT
  415. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:06.919229 [DEBUG] sofia.c:7283 Channel sofia/internal/1000@192.168.150.44:46118 entering state [calling][0]
  416. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1000@192.168.150.44:46118) State ROUTING
  417. cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:06.919229 [DEBUG] mod_sofia.c:93 sofia/internal/1000@192.168.1.131:46140 SOFIA INIT
  418. a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:06.919229 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/1000@192.168.1.131:46155 [a8d951e0-0282-4239-921e-4b5e7604c783]
  419. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:06.919229 [DEBUG] mod_sofia.c:154 sofia/internal/1000@192.168.150.44:46118 SOFIA ROUTING
  420. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:06.919229 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/1000@192.168.150.44:46118) State Change CS_ROUTING -> CS_CONSUME_MEDIA
  421. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1000@192.168.150.44:46118) State ROUTING going to sleep
  422. a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:06.919229 [DEBUG] mod_sofia.c:5028 (sofia/internal/1000@192.168.1.131:46155) State Change CS_NEW -> CS_INIT
  423. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@192.168.150.44:46118) Running State Change CS_CONSUME_MEDIA (Cur 4 Tot 71)
  424. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/1000@192.168.150.44:46118) State CONSUME_MEDIA
  425. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/1000@192.168.150.44:46118) State CONSUME_MEDIA going to sleep
  426. cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:06.919229 [DEBUG] sofia_glue.c:1299 sofia/internal/1000@192.168.1.131:46140 sending invite version: 1.9.0 git c093b2d 2018-03-20 14:32:52Z 64bit
  427. cff610de-5d42-482d-877c-c2748850a999 Local SDP:
  428. cff610de-5d42-482d-877c-c2748850a999 v=0
  429. cff610de-5d42-482d-877c-c2748850a999 o=FreeSWITCH 1521624212 1521624213 IN IP4 166.130.120.33
  430. cff610de-5d42-482d-877c-c2748850a999 s=FreeSWITCH
  431. cff610de-5d42-482d-877c-c2748850a999 c=IN IP4 166.130.120.33
  432. cff610de-5d42-482d-877c-c2748850a999 t=0 0
  433. cff610de-5d42-482d-877c-c2748850a999 m=audio 16414 RTP/AVP 9 102 0 8
  434. cff610de-5d42-482d-877c-c2748850a999 a=rtpmap:9 G722/8000
  435. cff610de-5d42-482d-877c-c2748850a999 a=rtpmap:102 opus/48000/2
  436. cff610de-5d42-482d-877c-c2748850a999 a=fmtp:102 useinbandfec=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40
  437. cff610de-5d42-482d-877c-c2748850a999 a=rtpmap:0 PCMU/8000
  438. cff610de-5d42-482d-877c-c2748850a999 a=rtpmap:8 PCMA/8000
  439. cff610de-5d42-482d-877c-c2748850a999 a=ptime:20
  440. cff610de-5d42-482d-877c-c2748850a999 a=sendrecv
  441. cff610de-5d42-482d-877c-c2748850a999 m=video 16480 RTP/AVP 103 104
  442. cff610de-5d42-482d-877c-c2748850a999 b=AS:1024
  443. cff610de-5d42-482d-877c-c2748850a999 a=rtpmap:103 VP8/90000
  444. cff610de-5d42-482d-877c-c2748850a999 a=rtpmap:104 H264/90000
  445. cff610de-5d42-482d-877c-c2748850a999 a=sendrecv
  446. cff610de-5d42-482d-877c-c2748850a999 a=rtcp-fb:103 ccm fir
  447. cff610de-5d42-482d-877c-c2748850a999 a=rtcp-fb:103 ccm tmmbr
  448. cff610de-5d42-482d-877c-c2748850a999 a=rtcp-fb:103 nack
  449. cff610de-5d42-482d-877c-c2748850a999 a=rtcp-fb:103 nack pli
  450. cff610de-5d42-482d-877c-c2748850a999 a=rtcp-fb:104 ccm fir
  451. cff610de-5d42-482d-877c-c2748850a999 a=rtcp-fb:104 ccm tmmbr
  452. cff610de-5d42-482d-877c-c2748850a999 a=rtcp-fb:104 nack
  453. cff610de-5d42-482d-877c-c2748850a999 a=rtcp-fb:104 nack pli
  454. cff610de-5d42-482d-877c-c2748850a999
  455. cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1000@192.168.1.131:46140 Standard INIT
  456. cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1000@192.168.1.131:46140) State Change CS_INIT -> CS_ROUTING
  457. cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1000@192.168.1.131:46140) State INIT going to sleep
  458. a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@192.168.1.131:46155) Running State Change CS_INIT (Cur 4 Tot 71)
  459. a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1000@192.168.1.131:46155) State INIT
  460. cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@192.168.1.131:46140) Running State Change CS_ROUTING (Cur 5 Tot 72)
  461. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:06.919229 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/1000@192.168.150.44:56245 [614ff42b-3e4b-4dd8-8413-012b87f773d4]
  462. a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:06.919229 [DEBUG] mod_sofia.c:93 sofia/internal/1000@192.168.1.131:46155 SOFIA INIT
  463. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:06.919229 [DEBUG] mod_sofia.c:5028 (sofia/internal/1000@192.168.150.44:56245) State Change CS_NEW -> CS_INIT
  464. cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:06.919229 [DEBUG] sofia.c:7283 Channel sofia/internal/1000@192.168.1.131:46140 entering state [calling][0]
  465. cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1000@192.168.1.131:46140) State ROUTING
  466. cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:06.919229 [DEBUG] mod_sofia.c:154 sofia/internal/1000@192.168.1.131:46140 SOFIA ROUTING
  467. cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:06.919229 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/1000@192.168.1.131:46140) State Change CS_ROUTING -> CS_CONSUME_MEDIA
  468. cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1000@192.168.1.131:46140) State ROUTING going to sleep
  469. cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@192.168.1.131:46140) Running State Change CS_CONSUME_MEDIA (Cur 5 Tot 72)
  470. a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:06.919229 [DEBUG] sofia_glue.c:1299 sofia/internal/1000@192.168.1.131:46155 sending invite version: 1.9.0 git c093b2d 2018-03-20 14:32:52Z 64bit
  471. a8d951e0-0282-4239-921e-4b5e7604c783 Local SDP:
  472. a8d951e0-0282-4239-921e-4b5e7604c783 v=0
  473. a8d951e0-0282-4239-921e-4b5e7604c783 o=FreeSWITCH 1521624236 1521624237 IN IP4 166.130.120.33
  474. a8d951e0-0282-4239-921e-4b5e7604c783 s=FreeSWITCH
  475. a8d951e0-0282-4239-921e-4b5e7604c783 c=IN IP4 166.130.120.33
  476. a8d951e0-0282-4239-921e-4b5e7604c783 t=0 0
  477. a8d951e0-0282-4239-921e-4b5e7604c783 m=audio 16390 RTP/AVP 9 102 0 8
  478. a8d951e0-0282-4239-921e-4b5e7604c783 a=rtpmap:9 G722/8000
  479. a8d951e0-0282-4239-921e-4b5e7604c783 a=rtpmap:102 opus/48000/2
  480. a8d951e0-0282-4239-921e-4b5e7604c783 a=fmtp:102 useinbandfec=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40
  481. a8d951e0-0282-4239-921e-4b5e7604c783 a=rtpmap:0 PCMU/8000
  482. a8d951e0-0282-4239-921e-4b5e7604c783 a=rtpmap:8 PCMA/8000
  483. a8d951e0-0282-4239-921e-4b5e7604c783 a=ptime:20
  484. a8d951e0-0282-4239-921e-4b5e7604c783 a=sendrecv
  485. a8d951e0-0282-4239-921e-4b5e7604c783 m=video 16384 RTP/AVP 103 104
  486. a8d951e0-0282-4239-921e-4b5e7604c783 b=AS:1024
  487. a8d951e0-0282-4239-921e-4b5e7604c783 a=rtpmap:103 VP8/90000
  488. a8d951e0-0282-4239-921e-4b5e7604c783 a=rtpmap:104 H264/90000
  489. a8d951e0-0282-4239-921e-4b5e7604c783 a=sendrecv
  490. a8d951e0-0282-4239-921e-4b5e7604c783 a=rtcp-fb:103 ccm fir
  491. a8d951e0-0282-4239-921e-4b5e7604c783 a=rtcp-fb:103 ccm tmmbr
  492. a8d951e0-0282-4239-921e-4b5e7604c783 a=rtcp-fb:103 nack
  493. a8d951e0-0282-4239-921e-4b5e7604c783 a=rtcp-fb:103 nack pli
  494. a8d951e0-0282-4239-921e-4b5e7604c783 a=rtcp-fb:104 ccm fir
  495. a8d951e0-0282-4239-921e-4b5e7604c783 a=rtcp-fb:104 ccm tmmbr
  496. a8d951e0-0282-4239-921e-4b5e7604c783 a=rtcp-fb:104 nack
  497. a8d951e0-0282-4239-921e-4b5e7604c783 a=rtcp-fb:104 nack pli
  498. a8d951e0-0282-4239-921e-4b5e7604c783
  499. a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1000@192.168.1.131:46155 Standard INIT
  500. a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1000@192.168.1.131:46155) State Change CS_INIT -> CS_ROUTING
  501. a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1000@192.168.1.131:46155) State INIT going to sleep
  502. cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/1000@192.168.1.131:46140) State CONSUME_MEDIA
  503. cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/1000@192.168.1.131:46140) State CONSUME_MEDIA going to sleep
  504. a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@192.168.1.131:46155) Running State Change CS_ROUTING (Cur 5 Tot 72)
  505. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@192.168.150.44:56245) Running State Change CS_INIT (Cur 5 Tot 72)
  506. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.919229 [NOTICE] switch_ivr_originate.c:2868 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
  507. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1000@192.168.150.44:56245) State INIT
  508. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:06.919229 [DEBUG] mod_sofia.c:93 sofia/internal/1000@192.168.150.44:56245 SOFIA INIT
  509. a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:06.919229 [DEBUG] sofia.c:7283 Channel sofia/internal/1000@192.168.1.131:46155 entering state [calling][0]
  510. a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1000@192.168.1.131:46155) State ROUTING
  511. a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:06.919229 [DEBUG] mod_sofia.c:154 sofia/internal/1000@192.168.1.131:46155 SOFIA ROUTING
  512. a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:06.919229 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/1000@192.168.1.131:46155) State Change CS_ROUTING -> CS_CONSUME_MEDIA
  513. a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1000@192.168.1.131:46155) State ROUTING going to sleep
  514. a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@192.168.1.131:46155) Running State Change CS_CONSUME_MEDIA (Cur 5 Tot 72)
  515. a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/1000@192.168.1.131:46155) State CONSUME_MEDIA
  516. a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/1000@192.168.1.131:46155) State CONSUME_MEDIA going to sleep
  517. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:06.919229 [DEBUG] sofia_glue.c:1299 sofia/internal/1000@192.168.150.44:56245 sending invite version: 1.9.0 git c093b2d 2018-03-20 14:32:52Z 64bit
  518. 614ff42b-3e4b-4dd8-8413-012b87f773d4 Local SDP:
  519. 614ff42b-3e4b-4dd8-8413-012b87f773d4 v=0
  520. 614ff42b-3e4b-4dd8-8413-012b87f773d4 o=FreeSWITCH 1521624228 1521624229 IN IP4 192.168.150.3
  521. 614ff42b-3e4b-4dd8-8413-012b87f773d4 s=FreeSWITCH
  522. 614ff42b-3e4b-4dd8-8413-012b87f773d4 c=IN IP4 192.168.150.3
  523. 614ff42b-3e4b-4dd8-8413-012b87f773d4 t=0 0
  524. 614ff42b-3e4b-4dd8-8413-012b87f773d4 m=audio 16398 RTP/AVP 9 102 0 8
  525. 614ff42b-3e4b-4dd8-8413-012b87f773d4 a=rtpmap:9 G722/8000
  526. 614ff42b-3e4b-4dd8-8413-012b87f773d4 a=rtpmap:102 opus/48000/2
  527. 614ff42b-3e4b-4dd8-8413-012b87f773d4 a=fmtp:102 useinbandfec=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40
  528. 614ff42b-3e4b-4dd8-8413-012b87f773d4 a=rtpmap:0 PCMU/8000
  529. 614ff42b-3e4b-4dd8-8413-012b87f773d4 a=rtpmap:8 PCMA/8000
  530. 614ff42b-3e4b-4dd8-8413-012b87f773d4 a=ptime:20
  531. 614ff42b-3e4b-4dd8-8413-012b87f773d4 a=sendrecv
  532. 614ff42b-3e4b-4dd8-8413-012b87f773d4 m=video 16476 RTP/AVP 103 104
  533. 614ff42b-3e4b-4dd8-8413-012b87f773d4 b=AS:1024
  534. 614ff42b-3e4b-4dd8-8413-012b87f773d4 a=rtpmap:103 VP8/90000
  535. 614ff42b-3e4b-4dd8-8413-012b87f773d4 a=rtpmap:104 H264/90000
  536. 614ff42b-3e4b-4dd8-8413-012b87f773d4 a=sendrecv
  537. 614ff42b-3e4b-4dd8-8413-012b87f773d4 a=rtcp-fb:103 ccm fir
  538. 614ff42b-3e4b-4dd8-8413-012b87f773d4 a=rtcp-fb:103 ccm tmmbr
  539. 614ff42b-3e4b-4dd8-8413-012b87f773d4 a=rtcp-fb:103 nack
  540. 614ff42b-3e4b-4dd8-8413-012b87f773d4 a=rtcp-fb:103 nack pli
  541. 614ff42b-3e4b-4dd8-8413-012b87f773d4 a=rtcp-fb:104 ccm fir
  542. 614ff42b-3e4b-4dd8-8413-012b87f773d4 a=rtcp-fb:104 ccm tmmbr
  543. 614ff42b-3e4b-4dd8-8413-012b87f773d4 a=rtcp-fb:104 nack
  544. 614ff42b-3e4b-4dd8-8413-012b87f773d4 a=rtcp-fb:104 nack pli
  545. 614ff42b-3e4b-4dd8-8413-012b87f773d4
  546. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1000@192.168.150.44:56245 Standard INIT
  547. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1000@192.168.150.44:56245) State Change CS_INIT -> CS_ROUTING
  548. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1000@192.168.150.44:56245) State INIT going to sleep
  549. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@192.168.150.44:56245) Running State Change CS_ROUTING (Cur 5 Tot 72)
  550. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:06.919229 [DEBUG] sofia.c:7283 Channel sofia/internal/1000@192.168.150.44:56245 entering state [calling][0]
  551. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1000@192.168.150.44:56245) State ROUTING
  552. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:06.919229 [DEBUG] mod_sofia.c:154 sofia/internal/1000@192.168.150.44:56245 SOFIA ROUTING
  553. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:06.919229 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/1000@192.168.150.44:56245) State Change CS_ROUTING -> CS_CONSUME_MEDIA
  554. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1000@192.168.150.44:56245) State ROUTING going to sleep
  555. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@192.168.150.44:56245) Running State Change CS_CONSUME_MEDIA (Cur 5 Tot 72)
  556. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/1000@192.168.150.44:56245) State CONSUME_MEDIA
  557. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/1000@192.168.150.44:56245) State CONSUME_MEDIA going to sleep
  558. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:06.999230 [DEBUG] sofia.c:7283 Channel sofia/internal/1000@192.168.150.44:56245 entering state [proceeding][180]
  559. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:06.999230 [NOTICE] sofia.c:7393 Ring-Ready sofia/internal/1000@192.168.150.44:56245!
  560. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:06.999230 [DEBUG] switch_channel.c:3354 (sofia/internal/1000@192.168.150.44:56245) Callstate Change DOWN -> RINGING
  561. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:07.009229 [DEBUG] switch_rtp.c:7484 Correct audio ip/port confirmed.
  562. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:07.029232 [DEBUG] switch_ivr_originate.c:1278 Raw Codec Activation Success L16@16000hz 1 channel 20ms
  563. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:07.029232 [DEBUG] switch_core_codec.c:223 sofia/internal/1001@192.168.150.3 Push codec L16:100
  564. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:07.029232 [DEBUG] switch_ivr_originate.c:1347 Play Ringback Tone [%(2000,4000,440,480)]
  565. cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:09.999259 [DEBUG] sofia.c:7283 Channel sofia/internal/1000@192.168.1.131:46140 entering state [terminated][503]
  566. cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:09.999259 [NOTICE] sofia.c:8476 Hangup sofia/internal/1000@192.168.1.131:46140 [CS_CONSUME_MEDIA] [NORMAL_TEMPORARY_FAILURE]
  567. a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:09.999259 [DEBUG] sofia.c:7283 Channel sofia/internal/1000@192.168.1.131:46155 entering state [terminated][503]
  568. a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:09.999259 [NOTICE] sofia.c:8476 Hangup sofia/internal/1000@192.168.1.131:46155 [CS_CONSUME_MEDIA] [NORMAL_TEMPORARY_FAILURE]
  569. a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:09.999259 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@192.168.1.131:46155) Running State Change CS_HANGUP (Cur 5 Tot 72)
  570. cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:09.999259 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@192.168.1.131:46140) Running State Change CS_HANGUP (Cur 5 Tot 72)
  571. a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:09.999259 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/1000@192.168.1.131:46155) Callstate Change DOWN -> HANGUP
  572. a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:09.999259 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1000@192.168.1.131:46155) State HANGUP
  573. cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:09.999259 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/1000@192.168.1.131:46140) Callstate Change DOWN -> HANGUP
  574. a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:09.999259 [DEBUG] mod_sofia.c:449 Channel sofia/internal/1000@192.168.1.131:46155 hanging up, cause: NORMAL_TEMPORARY_FAILURE
  575. cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:09.999259 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1000@192.168.1.131:46140) State HANGUP
  576. cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:09.999259 [DEBUG] mod_sofia.c:449 Channel sofia/internal/1000@192.168.1.131:46140 hanging up, cause: NORMAL_TEMPORARY_FAILURE
  577. a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:09.999259 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1000@192.168.1.131:46155 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE
  578. a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:09.999259 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1000@192.168.1.131:46155) State HANGUP going to sleep
  579. a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:09.999259 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/1000@192.168.1.131:46155) State Change CS_HANGUP -> CS_REPORTING
  580. a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:09.999259 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@192.168.1.131:46155) Running State Change CS_REPORTING (Cur 5 Tot 72)
  581. cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:09.999259 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1000@192.168.1.131:46140 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE
  582. cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:09.999259 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1000@192.168.1.131:46140) State HANGUP going to sleep
  583. a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:09.999259 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1000@192.168.1.131:46155) State REPORTING
  584. cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:09.999259 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/1000@192.168.1.131:46140) State Change CS_HANGUP -> CS_REPORTING
  585. cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:09.999259 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@192.168.1.131:46140) Running State Change CS_REPORTING (Cur 5 Tot 72)
  586. cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:09.999259 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1000@192.168.1.131:46140) State REPORTING
  587. 2018-03-21 09:57:09.999259 [DEBUG] mod_cdr_sqlite.c:102 Writing SQL to DB: INSERT INTO cdr VALUES ("1001","1001","1000","default","2018-03-21 09:57:06","","2018-03-21 09:57:09",3,0,"NORMAL_TEMPORARY_FAILURE","a8d951e0-0282-4239-921e-4b5e7604c783","","")
  588. 2018-03-21 09:57:09.999259 [DEBUG] mod_cdr_sqlite.c:102 Writing SQL to DB: INSERT INTO cdr VALUES ("1001","1001","1000","default","2018-03-21 09:57:06","","2018-03-21 09:57:09",3,0,"NORMAL_TEMPORARY_FAILURE","cff610de-5d42-482d-877c-c2748850a999","","")
  589. cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:09.999259 [DEBUG] switch_core_state_machine.c:174 sofia/internal/1000@192.168.1.131:46140 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE
  590. cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:09.999259 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1000@192.168.1.131:46140) State REPORTING going to sleep
  591. cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:09.999259 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/1000@192.168.1.131:46140) State Change CS_REPORTING -> CS_DESTROY
  592. cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:09.999259 [DEBUG] switch_core_session.c:1713 Session 70 (sofia/internal/1000@192.168.1.131:46140) Locked, Waiting on external entities
  593. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] sofia.c:7283 Channel sofia/internal/1000@192.168.150.44:56245 entering state [completing][200]
  594. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] sofia.c:7293 Remote SDP:
  595. 614ff42b-3e4b-4dd8-8413-012b87f773d4 v=0
  596. 614ff42b-3e4b-4dd8-8413-012b87f773d4 o=- 3874730898 3 IN IP4 192.168.1.131
  597. 614ff42b-3e4b-4dd8-8413-012b87f773d4 s=Cpc session
  598. 614ff42b-3e4b-4dd8-8413-012b87f773d4 c=IN IP4 166.130.120.33
  599. 614ff42b-3e4b-4dd8-8413-012b87f773d4 t=0 0
  600. 614ff42b-3e4b-4dd8-8413-012b87f773d4 m=audio 62112 RTP/AVP 9 102 0 8
  601. 614ff42b-3e4b-4dd8-8413-012b87f773d4 a=rtpmap:102 opus/48000/2
  602. 614ff42b-3e4b-4dd8-8413-012b87f773d4 a=fmtp:102 useinbandfec=1; usedtx=1; maxaveragebitrate=64000
  603. 614ff42b-3e4b-4dd8-8413-012b87f773d4 m=video 55568 RTP/AVP 103 104
  604. 614ff42b-3e4b-4dd8-8413-012b87f773d4 a=rtpmap:103 VP8/90000
  605. 614ff42b-3e4b-4dd8-8413-012b87f773d4 a=rtpmap:104 H264/90000
  606. 614ff42b-3e4b-4dd8-8413-012b87f773d4 a=fmtp:104 profile-level-id=42800b;packetization-mode=0
  607. 614ff42b-3e4b-4dd8-8413-012b87f773d4 a=rtcp-fb:* nack
  608. 614ff42b-3e4b-4dd8-8413-012b87f773d4 a=rtcp-fb:* nack pli
  609. 614ff42b-3e4b-4dd8-8413-012b87f773d4
  610. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [NOTICE] sofia.c:7296 Pre-Answer sofia/internal/1000@192.168.150.44:56245!
  611. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_channel.c:3482 (sofia/internal/1000@192.168.150.44:56245) Callstate Change RINGING -> EARLY
  612. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] sofia.c:7283 Channel sofia/internal/1000@192.168.150.44:56245 entering state [ready][200]
  613. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  614. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:5507 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match
  615. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [G722:9:8000:20:64000:1]/[opus:116:48000:20:0:1]
  616. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  617. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  618. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [opus:102:48000:20:0:1]/[G722:9:8000:20:64000:1]
  619. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [opus:102:48000:20:0:1]/[opus:116:48000:20:0:1]
  620. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:5507 Audio Codec Compare [opus:116:48000:20:0:1] ++++ is saved as a match
  621. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [opus:102:48000:20:0:1]/[PCMU:0:8000:20:64000:1]
  622. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [opus:102:48000:20:0:1]/[PCMA:8:8000:20:64000:1]
  623. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  624. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1]
  625. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  626. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:5507 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
  627. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  628. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  629. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1]
  630. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  631. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  632. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:5507 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
  633. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:3767 Set Codec sofia/internal/1000@192.168.150.44:56245 G722/8000 20 ms 160 samples 64000 bits 1 channels
  634. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_codec.c:111 sofia/internal/1000@192.168.150.44:56245 Original read codec set to G722:9
  635. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:5740 No 2833 in SDP. Liberal DTMF mode adding 101 as telephone-event.
  636. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:5769 sofia/internal/1000@192.168.150.44:56245 Set 2833 dtmf send payload to 101 recv payload to 101
  637. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:6052 Video Codec Compare [VP8:103]/[VP8:99]
  638. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:6084 Video Codec Compare [VP8:103] +++ is saved as a match
  639. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:6052 Video Codec Compare [VP8:103]/[H264:99]
  640. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:6052 Video Codec Compare [H264:104]/[VP8:99]
  641. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:6052 Video Codec Compare [H264:104]/[H264:99]
  642. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:6084 Video Codec Compare [H264:104] +++ is saved as a match
  643. 2018-03-21 09:57:10.029257 [DEBUG] switch_vpx.c:636 VPX VER:v1.6.0 VPX_IMAGE_ABI_VERSION:4 VPX_CODEC_ABI_VERSION:7
  644. 2018-03-21 09:57:10.029257 [DEBUG] switch_vpx.c:636 VPX VER:v1.6.0 VPX_IMAGE_ABI_VERSION:4 VPX_CODEC_ABI_VERSION:7
  645. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:3577 Set VIDEO Codec sofia/internal/1000@192.168.150.44:56245 VP8/90000 0 ms
  646. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:8486 AUDIO RTP [sofia/internal/1000@192.168.150.44:56245] 192.168.150.3 port 16398 -> 166.130.120.33 port 62112 codec: 9 ms: 20
  647. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_rtp.c:4276 Starting timer [soft] 160 bytes per 20ms
  648. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:8790 sofia/internal/1000@192.168.150.44:56245 Set 2833 dtmf send payload to 101
  649. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:8797 sofia/internal/1000@192.168.150.44:56245 Set 2833 dtmf receive payload to 101
  650. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:8820 sofia/internal/1000@192.168.150.44:56245 Set rtp dtmf delay to 40
  651. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_rtp.c:4291 Starting video timer.
  652. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:9315 VIDEO RTP [sofia/internal/1000@192.168.150.44:56245] 192.168.150.3:16476->166.130.120.33:55568 codec: 103 ms: 0 [SUCCESS]
  653. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:7478 sofia/internal/1000@192.168.150.44:56245 Starting Video thread
  654. 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:7344 sofia/internal/1000@192.168.150.44:56245 Video thread started. Echo is off
  655. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [INFO] switch_core_media.c:9395 Activating VIDEO RTCP PORT 55569 interval 1000 mux -1
  656. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_rtp.c:4672 RTCP send rate is: 1000 and packet rate is: 90000 Remote Port: 55569
  657. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_rtp.c:2567 Setting RTCP remote addr to 166.130.120.33:55569 2
  658. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [NOTICE] sofia.c:8421 Channel [sofia/internal/1000@192.168.150.44:56245] has been answered
  659. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.039230 [DEBUG] switch_channel.c:3781 (sofia/internal/1000@192.168.150.44:56245) Callstate Change EARLY -> ACTIVE
  660. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:10.049256 [DEBUG] switch_core_codec.c:248 sofia/internal/1001@192.168.150.3 Restore previous codec G722:9.
  661. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:10.049256 [NOTICE] switch_ivr_originate.c:3629 Hangup sofia/internal/1000@192.168.150.44:46118 [CS_CONSUME_MEDIA] [LOSE_RACE]
  662. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:10.049256 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@192.168.150.44:46118) Running State Change CS_HANGUP (Cur 5 Tot 72)
  663. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:10.049256 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/1000@192.168.150.44:46118) Callstate Change DOWN -> HANGUP
  664. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:10.049256 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1000@192.168.150.44:46118) State HANGUP
  665. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:10.049256 [DEBUG] mod_sofia.c:449 Channel sofia/internal/1000@192.168.150.44:46118 hanging up, cause: LOSE_RACE
  666. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:10.049256 [DEBUG] switch_core_media.c:8469 Audio params are unchanged for sofia/internal/1001@192.168.150.3.
  667. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:10.049256 [DEBUG] mod_sofia.c:881 Local SDP sofia/internal/1001@192.168.150.3:
  668. a0ca0a7f-9131-4c40-96e8-987fede99823 v=0
  669. a0ca0a7f-9131-4c40-96e8-987fede99823 o=FreeSWITCH 1521624204 1521624206 IN IP4 192.168.150.3
  670. a0ca0a7f-9131-4c40-96e8-987fede99823 s=FreeSWITCH
  671. a0ca0a7f-9131-4c40-96e8-987fede99823 c=IN IP4 192.168.150.3
  672. a0ca0a7f-9131-4c40-96e8-987fede99823 t=0 0
  673. a0ca0a7f-9131-4c40-96e8-987fede99823 m=audio 16422 RTP/AVP 9 101
  674. a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtpmap:9 G722/8000
  675. a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtpmap:101 telephone-event/8000
  676. a0ca0a7f-9131-4c40-96e8-987fede99823 a=fmtp:101 0-16
  677. a0ca0a7f-9131-4c40-96e8-987fede99823 a=ptime:20
  678. a0ca0a7f-9131-4c40-96e8-987fede99823 a=sendrecv
  679. a0ca0a7f-9131-4c40-96e8-987fede99823
  680. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:10.049256 [DEBUG] mod_sofia.c:513 Sending CANCEL to sofia/internal/1000@192.168.150.44:46118
  681. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:10.049256 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1000@192.168.150.44:46118 Standard HANGUP, cause: LOSE_RACE
  682. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:10.049256 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1000@192.168.150.44:46118) State HANGUP going to sleep
  683. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:10.049256 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/1000@192.168.150.44:46118) State Change CS_HANGUP -> CS_REPORTING
  684. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:10.049256 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@192.168.150.44:46118) Running State Change CS_REPORTING (Cur 5 Tot 72)
  685. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:10.049256 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1000@192.168.150.44:46118) State REPORTING
  686. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:10.049256 [NOTICE] switch_ivr_originate.c:3664 Channel [sofia/internal/1001@192.168.150.3] has been answered
  687. 2018-03-21 09:57:10.049256 [DEBUG] mod_cdr_sqlite.c:102 Writing SQL to DB: INSERT INTO cdr VALUES ("1001","1001","1000","default","2018-03-21 09:57:06","","2018-03-21 09:57:10",4,0,"LOSE_RACE","1a8b93af-e2fa-4189-a0e2-c6a94f451f45","","")
  688. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:10.049256 [DEBUG] switch_core_state_machine.c:174 sofia/internal/1000@192.168.150.44:46118 Standard REPORTING, cause: LOSE_RACE
  689. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:10.049256 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1000@192.168.150.44:46118) State REPORTING going to sleep
  690. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:10.049256 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/1000@192.168.150.44:46118) State Change CS_REPORTING -> CS_DESTROY
  691. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:10.049256 [DEBUG] switch_core_session.c:1713 Session 69 (sofia/internal/1000@192.168.150.44:46118) Locked, Waiting on external entities
  692. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:10.049256 [DEBUG] switch_channel.c:3781 (sofia/internal/1001@192.168.150.3) Callstate Change EARLY -> ACTIVE
  693. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:10.049256 [DEBUG] sofia.c:7283 Channel sofia/internal/1001@192.168.150.3 entering state [completed][200]
  694. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:10.049256 [DEBUG] switch_ivr_originate.c:3722 Originate Resulted in Success: [sofia/internal/1000@192.168.150.44:56245]
  695. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:10.049256 [NOTICE] switch_core_session.c:1731 Session 69 (sofia/internal/1000@192.168.150.44:46118) Ended
  696. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:10.049256 [NOTICE] switch_core_session.c:1735 Close Channel sofia/internal/1000@192.168.150.44:46118 [CS_DESTROY]
  697. cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:10.049256 [NOTICE] switch_core_session.c:1731 Session 70 (sofia/internal/1000@192.168.1.131:46140) Ended
  698. cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:10.049256 [NOTICE] switch_core_session.c:1735 Close Channel sofia/internal/1000@192.168.1.131:46140 [CS_DESTROY]
  699. cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:10.049256 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/1000@192.168.1.131:46140) Running State Change CS_DESTROY (Cur 3 Tot 72)
  700. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:10.049256 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/1000@192.168.150.44:46118) Running State Change CS_DESTROY (Cur 3 Tot 72)
  701. cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:10.049256 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1000@192.168.1.131:46140) State DESTROY
  702. cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:10.049256 [DEBUG] mod_sofia.c:354 sofia/internal/1000@192.168.1.131:46140 SOFIA DESTROY
  703. cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:10.049256 [DEBUG] switch_core_state_machine.c:181 sofia/internal/1000@192.168.1.131:46140 Standard DESTROY
  704. cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:10.049256 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1000@192.168.1.131:46140) State DESTROY going to sleep
  705. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:10.049256 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1000@192.168.150.44:46118) State DESTROY
  706. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:10.049256 [DEBUG] mod_sofia.c:354 sofia/internal/1000@192.168.150.44:46118 SOFIA DESTROY
  707. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:10.049256 [DEBUG] switch_core_state_machine.c:181 sofia/internal/1000@192.168.150.44:46118 Standard DESTROY
  708. 1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:10.049256 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1000@192.168.150.44:46118) State DESTROY going to sleep
  709. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:10.049256 [DEBUG] switch_ivr_originate.c:3722 Originate Resulted in Success: [sofia/internal/1000@192.168.150.44:56245]
  710. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.059226 [DEBUG] switch_ivr_bridge.c:1744 (sofia/internal/1000@192.168.150.44:56245) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
  711. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.059226 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@192.168.150.44:56245) Running State Change CS_EXCHANGE_MEDIA (Cur 3 Tot 72)
  712. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.059226 [DEBUG] switch_core_state_machine.c:653 (sofia/internal/1000@192.168.150.44:56245) State EXCHANGE_MEDIA
  713. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.059226 [DEBUG] mod_sofia.c:645 SOFIA EXCHANGE_MEDIA
  714. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:10.059226 [DEBUG] sofia.c:7283 Channel sofia/internal/1001@192.168.150.3 entering state [ready][200]
  715. a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:10.099234 [DEBUG] switch_core_state_machine.c:174 sofia/internal/1000@192.168.1.131:46155 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE
  716. a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:10.099234 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1000@192.168.1.131:46155) State REPORTING going to sleep
  717. a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:10.099234 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/1000@192.168.1.131:46155) State Change CS_REPORTING -> CS_DESTROY
  718. a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:10.099234 [DEBUG] switch_core_session.c:1713 Session 71 (sofia/internal/1000@192.168.1.131:46155) Locked, Waiting on external entities
  719. a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:10.099234 [NOTICE] switch_core_session.c:1731 Session 71 (sofia/internal/1000@192.168.1.131:46155) Ended
  720. a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:10.099234 [NOTICE] switch_core_session.c:1735 Close Channel sofia/internal/1000@192.168.1.131:46155 [CS_DESTROY]
  721. a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:10.099234 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/1000@192.168.1.131:46155) Running State Change CS_DESTROY (Cur 2 Tot 72)
  722. a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:10.099234 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1000@192.168.1.131:46155) State DESTROY
  723. a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:10.099234 [DEBUG] mod_sofia.c:354 sofia/internal/1000@192.168.1.131:46155 SOFIA DESTROY
  724. a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:10.099234 [DEBUG] switch_core_state_machine.c:181 sofia/internal/1000@192.168.1.131:46155 Standard DESTROY
  725. a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:10.099234 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1000@192.168.1.131:46155) State DESTROY going to sleep
  726. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:10.109255 [DEBUG] switch_rtp.c:7484 Correct audio ip/port confirmed.
  727. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.139258 [NOTICE] switch_vpx.c:410 VPX reset encoder picture from 320x240 to 352x288 1024 BW
  728. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.139258 [INFO] switch_rtp.c:6903 Auto Changing video RTCP port from 166.130.120.33:55569 to 192.168.150.44:55569
  729. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.139258 [DEBUG] switch_rtp.c:2567 Setting RTCP remote addr to 192.168.150.44:55569 2
  730. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:11.289256 [INFO] switch_rtp.c:7444 Auto Changing audio port from 166.130.120.33:62112 to 192.168.150.44:62112
  731. 2018-03-21 09:57:30.729257 [CRIT] mod_commands.c:6925 windows calling android
  732. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] sofia.c:7283 Channel sofia/internal/1001@192.168.150.3 entering state [received][100]
  733. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] sofia.c:7293 Remote SDP:
  734. a0ca0a7f-9131-4c40-96e8-987fede99823 v=0
  735. a0ca0a7f-9131-4c40-96e8-987fede99823 o=- 13166114225392269 2 IN IP4 192.168.150.38
  736. a0ca0a7f-9131-4c40-96e8-987fede99823 s=Bria 5 release 5.0.3 stamp 88308
  737. a0ca0a7f-9131-4c40-96e8-987fede99823 c=IN IP4 192.168.150.38
  738. a0ca0a7f-9131-4c40-96e8-987fede99823 t=0 0
  739. a0ca0a7f-9131-4c40-96e8-987fede99823 m=audio 51268 RTP/AVP 9 8 85 18 120 0 84 121 122 123 3 101
  740. a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtpmap:85 speex/8000
  741. a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtpmap:18 G729/8000
  742. a0ca0a7f-9131-4c40-96e8-987fede99823 a=fmtp:18 annexb=yes
  743. a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtpmap:120 opus/48000/2
  744. a0ca0a7f-9131-4c40-96e8-987fede99823 a=fmtp:120 useinbandfec=1; usedtx=1; maxaveragebitrate=64000
  745. a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtpmap:84 speex/16000
  746. a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtpmap:121 SILK/8000
  747. a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtpmap:122 SILK/16000
  748. a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtpmap:123 SILK/24000
  749. a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtpmap:101 telephone-event/8000
  750. a0ca0a7f-9131-4c40-96e8-987fede99823 a=fmtp:101 0-15
  751. a0ca0a7f-9131-4c40-96e8-987fede99823 m=video 53822 RTP/AVP 100 127 126
  752. a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtpmap:100 VP8/90000
  753. a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtpmap:127 H264/90000
  754. a0ca0a7f-9131-4c40-96e8-987fede99823 a=fmtp:127 profile-level-id=42800c;packetization-mode=0
  755. a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtpmap:126 H264/90000
  756. a0ca0a7f-9131-4c40-96e8-987fede99823 a=fmtp:126 profile-level-id=42800c;packetization-mode=1
  757. a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtcp-fb:* nack
  758. a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtcp-fb:* nack pli
  759. a0ca0a7f-9131-4c40-96e8-987fede99823
  760. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [G722:9:8000:20:64000:1]/[opus:116:48000:20:0:1]
  761. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  762. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5507 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match
  763. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  764. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  765. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1]
  766. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  767. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  768. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  769. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5507 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
  770. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [speex:85:8000:20:0:1]/[opus:116:48000:20:0:1]
  771. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [speex:85:8000:20:0:1]/[G722:9:8000:20:64000:1]
  772. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [speex:85:8000:20:0:1]/[PCMU:0:8000:20:64000:1]
  773. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [speex:85:8000:20:0:1]/[PCMA:8:8000:20:64000:1]
  774. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [G729:18:8000:20:8000:1]/[opus:116:48000:20:0:1]
  775. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [G729:18:8000:20:8000:1]/[G722:9:8000:20:64000:1]
  776. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
  777. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
  778. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [opus:120:48000:20:0:1]/[opus:116:48000:20:0:1]
  779. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5507 Audio Codec Compare [opus:116:48000:20:0:1] ++++ is saved as a match
  780. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [opus:120:48000:20:0:1]/[G722:9:8000:20:64000:1]
  781. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [opus:120:48000:20:0:1]/[PCMU:0:8000:20:64000:1]
  782. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [opus:120:48000:20:0:1]/[PCMA:8:8000:20:64000:1]
  783. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1]
  784. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  785. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  786. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5507 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
  787. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  788. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [speex:84:16000:20:0:1]/[opus:116:48000:20:0:1]
  789. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [speex:84:16000:20:0:1]/[G722:9:8000:20:64000:1]
  790. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [speex:84:16000:20:0:1]/[PCMU:0:8000:20:64000:1]
  791. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [speex:84:16000:20:0:1]/[PCMA:8:8000:20:64000:1]
  792. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [SILK:121:8000:20:0:1]/[opus:116:48000:20:0:1]
  793. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [SILK:121:8000:20:0:1]/[G722:9:8000:20:64000:1]
  794. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [SILK:121:8000:20:0:1]/[PCMU:0:8000:20:64000:1]
  795. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [SILK:121:8000:20:0:1]/[PCMA:8:8000:20:64000:1]
  796. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [SILK:122:16000:20:0:1]/[opus:116:48000:20:0:1]
  797. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [SILK:122:16000:20:0:1]/[G722:9:8000:20:64000:1]
  798. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [SILK:122:16000:20:0:1]/[PCMU:0:8000:20:64000:1]
  799. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [SILK:122:16000:20:0:1]/[PCMA:8:8000:20:64000:1]
  800. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [SILK:123:24000:20:0:1]/[opus:116:48000:20:0:1]
  801. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [SILK:123:24000:20:0:1]/[G722:9:8000:20:64000:1]
  802. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [SILK:123:24000:20:0:1]/[PCMU:0:8000:20:64000:1]
  803. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [SILK:123:24000:20:0:1]/[PCMA:8:8000:20:64000:1]
  804. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [GSM:3:8000:20:13200:1]/[opus:116:48000:20:0:1]
  805. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [GSM:3:8000:20:13200:1]/[G722:9:8000:20:64000:1]
  806. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMU:0:8000:20:64000:1]
  807. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMA:8:8000:20:64000:1]
  808. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5368 Set telephone-event payload to 101@8000
  809. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5711 Set telephone-event payload to 101@8000
  810. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5769 sofia/internal/1001@192.168.150.3 Set 2833 dtmf send payload to 101 recv payload to 101
  811. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:6052 Video Codec Compare [VP8:100]/[VP8:99]
  812. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:6052 Video Codec Compare [VP8:100]/[H264:99]
  813. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:6052 Video Codec Compare [H264:127]/[VP8:99]
  814. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:6052 Video Codec Compare [H264:127]/[H264:99]
  815. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:6052 Video Codec Compare [H264:126]/[VP8:99]
  816. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:6052 Video Codec Compare [H264:126]/[H264:99]
  817. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:6095 No matches with FTMP, fallback to ignoring FMTP
  818. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:6052 Video Codec Compare [VP8:100]/[VP8:99]
  819. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:6052 Video Codec Compare [VP8:100]/[H264:99]
  820. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:6052 Video Codec Compare [H264:127]/[VP8:99]
  821. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:6052 Video Codec Compare [H264:127]/[H264:99]
  822. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:6052 Video Codec Compare [H264:126]/[VP8:99]
  823. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:6052 Video Codec Compare [H264:126]/[H264:99]
  824. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:6103 No matches with inherit_codec, fallback to ignoring PT
  825. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:6052 Video Codec Compare [VP8:100]/[VP8:99]
  826. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:6084 Video Codec Compare [VP8:100] +++ is saved as a match
  827. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:6052 Video Codec Compare [VP8:100]/[H264:99]
  828. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:6052 Video Codec Compare [H264:127]/[VP8:99]
  829. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:6052 Video Codec Compare [H264:127]/[H264:99]
  830. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:6084 Video Codec Compare [H264:127] +++ is saved as a match
  831. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:6052 Video Codec Compare [H264:126]/[VP8:99]
  832. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:6052 Video Codec Compare [H264:126]/[H264:99]
  833. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:6084 Video Codec Compare [H264:126] +++ is saved as a match
  834. 2018-03-21 09:57:48.349233 [DEBUG] switch_vpx.c:636 VPX VER:v1.6.0 VPX_IMAGE_ABI_VERSION:4 VPX_CODEC_ABI_VERSION:7
  835. 2018-03-21 09:57:48.349233 [DEBUG] switch_vpx.c:636 VPX VER:v1.6.0 VPX_IMAGE_ABI_VERSION:4 VPX_CODEC_ABI_VERSION:7
  836. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:3577 Set VIDEO Codec sofia/internal/1001@192.168.150.3 VP8/90000 0 ms
  837. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:8469 Audio params are unchanged for sofia/internal/1001@192.168.150.3.
  838. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_rtp.c:4291 Starting video timer.
  839. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:9315 VIDEO RTP [sofia/internal/1001@192.168.150.3] 192.168.150.3:16478->192.168.150.38:53822 codec: 100 ms: 0 [SUCCESS]
  840. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:7478 sofia/internal/1001@192.168.150.3 Starting Video thread
  841. 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:7344 sofia/internal/1001@192.168.150.3 Video thread started. Echo is off
  842. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [INFO] switch_core_media.c:9395 Activating VIDEO RTCP PORT 53823 interval 1000 mux -1
  843. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_rtp.c:4672 RTCP send rate is: 1000 and packet rate is: 90000 Remote Port: 53823
  844. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_rtp.c:2567 Setting RTCP remote addr to 192.168.150.38:53823 2
  845. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] sofia.c:8200 Processing updated SDP
  846. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.369257 [DEBUG] sofia.c:7283 Channel sofia/internal/1001@192.168.150.3 entering state [completed][200]
  847. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.369257 [DEBUG] sofia.c:7283 Channel sofia/internal/1001@192.168.150.3 entering state [ready][200]
  848. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.469257 [DEBUG] switch_rtp.c:6924 Correct video RTCP ip/port confirmed.
  849. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:50.399260 [DEBUG] switch_rtp.c:1885 rtcp_stats_init: video ssrc[1582063745] base_seq[14807]
  850. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:50.469256 [DEBUG] switch_rtp.c:7484 Correct video ip/port confirmed.
  851. 2018-03-21 09:58:22.619259 [WARNING] switch_core_file.c:380 File has 2 channels, muxing to 1 channel will occur.
  852. 2018-03-21 09:58:36.909256 [CRIT] mod_commands.c:6925 windows sends video, but android cannot see
  853. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:58:41.549257 [DEBUG] switch_rtp.c:1885 rtcp_stats_init: video ssrc[129502379] base_seq[14498]
  854. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:58:41.729245 [INFO] switch_rtp.c:7444 Auto Changing video port from 166.130.120.33:55568 to 192.168.150.44:55568
  855. 2018-03-21 09:58:58.189257 [DEBUG] mod_commands.c:6925 android send video, not both can see eachother
  856. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:59:15.789257 [NOTICE] sofia.c:1079 Hangup sofia/internal/1000@192.168.150.44:56245 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING]
  857. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:59:15.789257 [DEBUG] switch_ivr_bridge.c:848 Ending video thread.
  858. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:59:15.789257 [DEBUG] switch_ivr_bridge.c:906 Ending video thread.
  859. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:59:15.789257 [DEBUG] switch_ivr_bridge.c:255 sofia/internal/1000@192.168.150.44:56245 video thread ended.
  860. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:59:15.789257 [DEBUG] switch_ivr_bridge.c:257 sofia/internal/1000@192.168.150.44:56245 skip receive message [DISPLAY] (channel is hungup already)
  861. 2018-03-21 09:59:15.789257 [DEBUG] switch_core_media.c:7445 sofia/internal/1000@192.168.150.44:56245 Video thread ended
  862. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:59:15.799258 [DEBUG] switch_ivr_bridge.c:917 BRIDGE THREAD DONE [sofia/internal/1000@192.168.150.44:56245]
  863. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:59:15.799258 [DEBUG] switch_core_state_machine.c:653 (sofia/internal/1000@192.168.150.44:56245) State EXCHANGE_MEDIA going to sleep
  864. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:59:15.799258 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@192.168.150.44:56245) Running State Change CS_HANGUP (Cur 2 Tot 72)
  865. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:59:15.799258 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/1000@192.168.150.44:56245) Callstate Change ACTIVE -> HANGUP
  866. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:59:15.799258 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1000@192.168.150.44:56245) State HANGUP
  867. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:59:15.799258 [DEBUG] mod_sofia.c:449 Channel sofia/internal/1000@192.168.150.44:56245 hanging up, cause: NORMAL_CLEARING
  868. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:59:15.799258 [DEBUG] switch_ivr_bridge.c:825 sofia/internal/1000@192.168.150.44:56245 ending bridge by request from write function
  869. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:59:15.799258 [DEBUG] switch_ivr_bridge.c:848 Ending video thread.
  870. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:59:15.799258 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1000@192.168.150.44:56245 Standard HANGUP, cause: NORMAL_CLEARING
  871. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:59:15.799258 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1000@192.168.150.44:56245) State HANGUP going to sleep
  872. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:59:15.799258 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/1000@192.168.150.44:56245) State Change CS_HANGUP -> CS_REPORTING
  873. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:59:15.799258 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@192.168.150.44:56245) Running State Change CS_REPORTING (Cur 2 Tot 72)
  874. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:59:15.799258 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1000@192.168.150.44:56245) State REPORTING
  875. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:59:15.799258 [DEBUG] switch_ivr_bridge.c:906 Ending video thread.
  876. 2018-03-21 09:59:15.799258 [DEBUG] mod_cdr_sqlite.c:102 Writing SQL to DB: INSERT INTO cdr VALUES ("1001","1001","1000","default","2018-03-21 09:57:06","2018-03-21 09:57:10","2018-03-21 09:59:15",129,125,"NORMAL_CLEARING","614ff42b-3e4b-4dd8-8413-012b87f773d4","","1000")
  877. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:59:15.799258 [DEBUG] switch_core_state_machine.c:174 sofia/internal/1000@192.168.150.44:56245 Standard REPORTING, cause: NORMAL_CLEARING
  878. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:59:15.799258 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1000@192.168.150.44:56245) State REPORTING going to sleep
  879. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:59:15.799258 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/1000@192.168.150.44:56245) State Change CS_REPORTING -> CS_DESTROY
  880. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:59:15.799258 [DEBUG] switch_core_session.c:1713 Session 72 (sofia/internal/1000@192.168.150.44:56245) Locked, Waiting on external entities
  881. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:59:15.819248 [DEBUG] switch_ivr_bridge.c:255 sofia/internal/1001@192.168.150.3 video thread ended.
  882. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:59:15.829239 [DEBUG] switch_ivr_bridge.c:917 BRIDGE THREAD DONE [sofia/internal/1001@192.168.150.3]
  883. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:59:15.839233 [NOTICE] switch_ivr_bridge.c:1895 Hangup sofia/internal/1001@192.168.150.3 [CS_EXECUTE] [NORMAL_CLEARING]
  884. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:59:15.839233 [NOTICE] switch_core_session.c:1731 Session 72 (sofia/internal/1000@192.168.150.44:56245) Ended
  885. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:59:15.839233 [NOTICE] switch_core_session.c:1735 Close Channel sofia/internal/1000@192.168.150.44:56245 [CS_DESTROY]
  886. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:59:15.839233 [DEBUG] switch_core_session.c:2885 sofia/internal/1001@192.168.150.3 skip receive message [PHONE_EVENT] (channel is hungup already)
  887. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:59:15.839233 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/1001@192.168.150.3) State EXECUTE going to sleep
  888. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:59:15.839233 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1001@192.168.150.3) Running State Change CS_HANGUP (Cur 1 Tot 72)
  889. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:59:15.839233 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/1000@192.168.150.44:56245) Running State Change CS_DESTROY (Cur 1 Tot 72)
  890. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:59:15.839233 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/1001@192.168.150.3) Callstate Change ACTIVE -> HANGUP
  891. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:59:15.839233 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1000@192.168.150.44:56245) State DESTROY
  892. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:59:15.839233 [DEBUG] mod_sofia.c:354 sofia/internal/1000@192.168.150.44:56245 SOFIA DESTROY
  893. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:59:15.839233 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1001@192.168.150.3) State HANGUP
  894. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:59:15.839233 [DEBUG] switch_core_state_machine.c:181 sofia/internal/1000@192.168.150.44:56245 Standard DESTROY
  895. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:59:15.839233 [DEBUG] mod_sofia.c:443 sofia/internal/1001@192.168.150.3 Overriding SIP cause 480 with 200 from the other leg
  896. 614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:59:15.839233 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1000@192.168.150.44:56245) State DESTROY going to sleep
  897. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:59:15.839233 [DEBUG] mod_sofia.c:449 Channel sofia/internal/1001@192.168.150.3 hanging up, cause: NORMAL_CLEARING
  898. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:59:15.839233 [DEBUG] mod_sofia.c:502 Sending BYE to sofia/internal/1001@192.168.150.3
  899. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:59:15.839233 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1001@192.168.150.3 Standard HANGUP, cause: NORMAL_CLEARING
  900. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:59:15.839233 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1001@192.168.150.3) State HANGUP going to sleep
  901. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:59:15.839233 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/1001@192.168.150.3) State Change CS_HANGUP -> CS_REPORTING
  902. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:59:15.839233 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1001@192.168.150.3) Running State Change CS_REPORTING (Cur 1 Tot 72)
  903. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:59:15.839233 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1001@192.168.150.3) State REPORTING
  904. 2018-03-21 09:59:15.839233 [DEBUG] mod_cdr_sqlite.c:102 Writing SQL to DB: INSERT INTO cdr VALUES ("1001","1001","1000","default","2018-03-21 09:57:06","2018-03-21 09:57:10","2018-03-21 09:59:15",129,125,"NORMAL_CLEARING","a0ca0a7f-9131-4c40-96e8-987fede99823","614ff42b-3e4b-4dd8-8413-012b87f773d4","1001")
  905. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:59:15.839233 [DEBUG] switch_core_state_machine.c:174 sofia/internal/1001@192.168.150.3 Standard REPORTING, cause: NORMAL_CLEARING
  906. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:59:15.839233 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1001@192.168.150.3) State REPORTING going to sleep
  907. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:59:15.839233 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/1001@192.168.150.3) State Change CS_REPORTING -> CS_DESTROY
  908. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:59:15.839233 [DEBUG] switch_core_session.c:1713 Session 68 (sofia/internal/1001@192.168.150.3) Locked, Waiting on external entities
  909. 2018-03-21 09:59:15.879233 [DEBUG] switch_core_media.c:7445 sofia/internal/1001@192.168.150.3 Video thread ended
  910. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:59:15.879233 [NOTICE] switch_core_session.c:1731 Session 68 (sofia/internal/1001@192.168.150.3) Ended
  911. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:59:15.879233 [NOTICE] switch_core_session.c:1735 Close Channel sofia/internal/1001@192.168.150.3 [CS_DESTROY]
  912. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:59:15.879233 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/1001@192.168.150.3) Running State Change CS_DESTROY (Cur 0 Tot 72)
  913. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:59:15.879233 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1001@192.168.150.3) State DESTROY
  914. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:59:15.879233 [DEBUG] mod_sofia.c:354 sofia/internal/1001@192.168.150.3 SOFIA DESTROY
  915. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:59:15.879233 [DEBUG] switch_core_state_machine.c:181 sofia/internal/1001@192.168.150.3 Standard DESTROY
  916. a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:59:15.879233 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1001@192.168.150.3) State DESTROY going to sleep
  917. 2018-03-21 09:59:26.559258 [NOTICE] sofia_reg.c:448 Registering flowroute
  918. 2018-03-21 09:59:26.829256 [DEBUG] sofia_reg.c:2435 Changing expire time to 546 by request of proxy sip:sip.flowroute.com
  919. 2018-03-21 09:59:42.769257 [WARNING] switch_core_file.c:380 File has 2 channels, muxing to 1 channel will occur.
  920.