=~=~=~=~=~=~=~=~=~=~=~= PuTTY log 2012.11.15 23:01:25 =~=~=~=~=~=~=~=~=~=~=~=

]0;root@TAS-FSwitch: ~root@TAS-FSwitch:~# fs_cli
            _____ ____     ____ _     ___              
           |  ___/ ___|   / ___| |   |_ _|             
           | |_  \___ \  | |   | |    | |            
           |  _|  ___) | | |___| |___ | |              
           |_|   |____/   \____|_____|___|            

*******************************************************
* Anthony Minessale II, Ken Rice,                     *
* Michael Jerris, Travis Cross                        *
* FreeSWITCH (http://www.freeswitch.org)              *
* Paypal Donations Appreciated: paypal@freeswitch.org *
* Brought to you by ClueCon http://www.cluecon.com/   *
*******************************************************


.========================================================================================================.
|    ____                       _____        ____ _             ____              _ _ ____               |
|   / ___|___  _ __ ___   ___  |_   _|__    / ___| |_   _  ___ / ___|___  _ __   ( ) |___ \              |
|  | |   / _ \| '_ ` _ \ / _ \   | |/ _ \  | |   | | | | |/ _ \ |   / _ \| '_ \  |/| | __) |             |
|  | |__| (_) | | | | | |  __/   | | (_) | | |___| | |_| |  __/ |__| (_) | | | |   | |/ __/              |
|   \____\___/|_| |_| |_|\___|   |_|\___/   \____|_|\__,_|\___|\____\___/|_| |_|   |_|_____|             |
|                                                                                                        |
|    ____ _     _                              _   _ ____    _                                           |
|   / ___| |__ (_) ___ __ _  __ _  ___        | | | / ___|  / \                                          |
|  | |   | '_ \| |/ __/ _` |/ _` |/ _ \       | | | \___ \ / _ \                                         |
|  | |___| | | | | (_| (_| | (_| | (_) |  _   | |_| |___) / ___ \                                        |
|   \____|_| |_|_|\___\__,_|\__, |\___/  ( )   \___/|____/_/   \_\                                       |
|                           |___/        |/                                                              |
|      _                         _     _____ _   _                ___  _   _       ____   ___  _ ____    |
|     / \  _   _  __ _ _   _ ___| |_  |___  | |_| |__            / _ \| |_| |__   |___ \ / _ \/ |___ \   |
|    / _ \| | | |/ _` | | | / __| __|    / /| __| '_ \   _____  | (_) | __| '_ \    __) | | | | | __) |  |
|   / ___ \ |_| | (_| | |_| \__ \ |_    / / | |_| | | | |_____|  \__, | |_| | | |  / __/| |_| | |/ __/   |
|  /_/   \_\__,_|\__, |\__,_|___/\__|  /_/   \__|_| |_|            /_/ \__|_| |_| |_____|\___/|_|_____|  |
|                |___/                                                                                   |
|                                           _                                                            |
|  __      ____      ____      __       ___| |_   _  ___  ___ ___  _ __         ___ ___  _ __ ___        |
|  \ \ /\ / /\ \ /\ / /\ \ /\ / /      / __| | | | |/ _ \/ __/ _ \| '_ \       / __/ _ \| '_ ` _ \       |
|   \ V  V /  \ V  V /  \ V  V /   _  | (__| | |_| |  __/ (_| (_) | | | |  _  | (_| (_) | | | | | |      |
|    \_/\_/    \_/\_/    \_/\_/   (_)  \___|_|\__,_|\___|\___\___/|_| |_| (_)  \___\___/|_| |_| |_|      |
|                                                                                                        |
.========================================================================================================.


Type /help <enter> to see a list of commands


+OK log level  [7]
freeswitch@internal> sofia reload
Unknown Command [reload]

freeswitch@internal> reload xml
-ERR unloading module [No such module!]
+OK Reloading XML
-ERR loading module [module load file routine returned an error]


2012-11-15 23:02:15.991261 [ERR] switch_xml.c:1323 Couldnt open /usr/local/freeswitch/conf/dialplan/public/test.com/*.xml (No such file or directory)
freeswitch@internal> 
freeswitch@internal> 
2012-11-15 23:02:16.071250 [DEBUG] mod_cidlookup.c:134 Connecting to dsn: phone
freeswitch@internal> 

2012-11-15 23:02:16.071250 [ERR] switch_odbc.c:365 STATE: IM002 CODE 0 ERROR: [unixODBC][Driver Manager]Data source name not found, and no default driver specified

freeswitch@internal> 

2012-11-15 23:02:16.071250 [CRIT] switch_core_sqldb.c:419 Failure to connect to ODBC phone!
freeswitch@internal> 

2012-11-15 23:02:16.071250 [CRIT] mod_cidlookup.c:137 Cannot Open ODBC Database!
freeswitch@internal> 

2012-11-15 23:02:16.071250 [INFO] mod_enum.c:871 ENUM Reloaded
freeswitch@internal> 

2012-11-15 23:02:16.071250 [INFO] mod_pocketsphinx.c:482 PocketSphinx Reloaded
freeswitch@internal> 

2012-11-15 23:02:16.071250 [DEBUG] mod_spandsp.c:627 Adding tone_descriptor: 1
freeswitch@internal> 

2012-11-15 23:02:16.071250 [DEBUG] mod_spandsp.c:648 Adding tone_descriptor: 1, tone: CED_TONE(0)
freeswitch@internal> 

2012-11-15 23:02:16.071250 [DEBUG] mod_spandsp.c:683 Adding tone_descriptor: 1, tone: CED_TONE(0), element (2100, 0, 500, 0)
freeswitch@internal> 

2012-11-15 23:02:16.071250 [DEBUG] mod_spandsp.c:648 Adding tone_descriptor: 1, tone: SIT(1)
freeswitch@internal> 

2012-11-15 23:02:16.071250 [DEBUG] mod_spandsp.c:683 Adding tone_descriptor: 1, tone: SIT(1), element (950, 0, 256, 400)
freeswitch@internal> 

2012-11-15 23:02:16.071250 [DEBUG] mod_spandsp.c:683 Adding tone_descriptor: 1, tone: SIT(1), element (1400, 0, 256, 400)
freeswitch@internal> 

2012-11-15 23:02:16.071250 [DEBUG] mod_spandsp.c:683 Adding tone_descriptor: 1, tone: SIT(1), element (1800, 0, 256, 400)
freeswitch@internal> 

2012-11-15 23:02:16.071250 [DEBUG] mod_spandsp.c:648 Adding tone_descriptor: 1, tone: REORDER_TONE(2)
freeswitch@internal> 

2012-11-15 23:02:16.071250 [DEBUG] mod_spandsp.c:683 Adding tone_descriptor: 1, tone: REORDER_TONE(2), element (480, 620, 224, 272)
freeswitch@internal> 

2012-11-15 23:02:16.071250 [DEBUG] mod_spandsp.c:683 Adding tone_descriptor: 1, tone: REORDER_TONE(2), element (0, 0, 224, 272)
freeswitch@internal> 

2012-11-15 23:02:16.071250 [DEBUG] mod_spandsp.c:648 Adding tone_descriptor: 1, tone: BUSY_TONE(3)
freeswitch@internal> 

2012-11-15 23:02:16.071250 [DEBUG] mod_spandsp.c:683 Adding tone_descriptor: 1, tone: BUSY_TONE(3), element (480, 620, 464, 516)
freeswitch@internal> 

2012-11-15 23:02:16.071250 [DEBUG] mod_spandsp.c:683 Adding tone_descriptor: 1, tone: BUSY_TONE(3), element (0, 0, 464, 516)
freeswitch@internal> 

2012-11-15 23:02:16.071250 [DEBUG] mod_spandsp.c:627 Adding tone_descriptor: 44
freeswitch@internal> 

2012-11-15 23:02:16.071250 [DEBUG] mod_spandsp.c:648 Adding tone_descriptor: 44, tone: CED_TONE(0)
freeswitch@internal> 

2012-11-15 23:02:16.071250 [DEBUG] mod_spandsp.c:683 Adding tone_descriptor: 44, tone: CED_TONE(0), element (2100, 0, 500, 0)
freeswitch@internal> 

2012-11-15 23:02:16.071250 [CRIT] switch_loadable_module.c:1300 Error Loading module /usr/local/freeswitch/mod/xml.so
**/usr/local/freeswitch/mod/xml.so: cannot open shared object file: No such file or directory**
freeswitch@internal> 

2012-11-15 23:02:16.071250 [DEBUG] mod_spandsp.c:648 Adding tone_descriptor: 44, tone: SIT(1)
freeswitch@internal> 

2012-11-15 23:02:16.071250 [DEBUG] mod_spandsp.c:683 Adding tone_descriptor: 44, tone: SIT(1), element (950, 0, 256, 400)
freeswitch@internal> 

2012-11-15 23:02:16.071250 [DEBUG] mod_spandsp.c:683 Adding tone_descriptor: 44, tone: SIT(1), element (1400, 0, 256, 400)
freeswitch@internal> 

2012-11-15 23:02:16.071250 [DEBUG] mod_spandsp.c:683 Adding tone_descriptor: 44, tone: SIT(1), element (1800, 0, 256, 400)
freeswitch@internal> 

2012-11-15 23:02:16.071250 [DEBUG] mod_spandsp.c:648 Adding tone_descriptor: 44, tone: REORDER_TONE(2)
freeswitch@internal> 

2012-11-15 23:02:16.071250 [DEBUG] mod_spandsp.c:683 Adding tone_descriptor: 44, tone: REORDER_TONE(2), element (400, 0, 368, 416)
freeswitch@internal> 

2012-11-15 23:02:16.071250 [DEBUG] mod_spandsp.c:683 Adding tone_descriptor: 44, tone: REORDER_TONE(2), element (0, 0, 336, 368)
freeswitch@internal> 

2012-11-15 23:02:16.071250 [DEBUG] mod_spandsp.c:683 Adding tone_descriptor: 44, tone: REORDER_TONE(2), element (400, 0, 256, 288)
freeswitch@internal> 

2012-11-15 23:02:16.071250 [DEBUG] mod_spandsp.c:683 Adding tone_descriptor: 44, tone: REORDER_TONE(2), element (0, 0, 512, 544)
freeswitch@internal> 

2012-11-15 23:02:16.071250 [DEBUG] mod_spandsp.c:648 Adding tone_descriptor: 44, tone: BUSY_TONE(3)
freeswitch@internal> 

2012-11-15 23:02:16.071250 [DEBUG] mod_spandsp.c:683 Adding tone_descriptor: 44, tone: BUSY_TONE(3), element (400, 0, 352, 384)
freeswitch@internal> 

2012-11-15 23:02:16.071250 [DEBUG] mod_spandsp.c:683 Adding tone_descriptor: 44, tone: BUSY_TONE(3), element (0, 0, 352, 384)
freeswitch@internal> 

2012-11-15 23:02:16.071250 [DEBUG] mod_spandsp.c:683 Adding tone_descriptor: 44, tone: BUSY_TONE(3), element (400, 0, 352, 384)
freeswitch@internal> 

2012-11-15 23:02:16.071250 [DEBUG] mod_spandsp.c:683 Adding tone_descriptor: 44, tone: BUSY_TONE(3), element (0, 0, 352, 384)
freeswitch@internal> 

2012-11-15 23:02:16.071250 [DEBUG] mod_spandsp.c:627 Adding tone_descriptor: 49
freeswitch@internal> 

2012-11-15 23:02:16.071250 [DEBUG] mod_spandsp.c:648 Adding tone_descriptor: 49, tone: CED_TONE(0)
freeswitch@internal> 

2012-11-15 23:02:16.071250 [DEBUG] mod_spandsp.c:683 Adding tone_descriptor: 49, tone: CED_TONE(0), element (2100, 0, 500, 0)
freeswitch@internal> 

2012-11-15 23:02:16.071250 [DEBUG] mod_spandsp.c:648 Adding tone_descriptor: 49, tone: SIT(1)
freeswitch@internal> 

2012-11-15 23:02:16.071250 [DEBUG] mod_spandsp.c:683 Adding tone_descriptor: 49, tone: SIT(1), element (900, 0, 256, 400)
freeswitch@internal> 

2012-11-15 23:02:16.071250 [DEBUG] mod_spandsp.c:683 Adding tone_descriptor: 49, tone: SIT(1), element (1400, 0, 256, 400)
freeswitch@internal> 

2012-11-15 23:02:16.071250 [DEBUG] mod_spandsp.c:683 Adding tone_descriptor: 49, tone: SIT(1), element (1800, 0, 256, 400)
freeswitch@internal> 

2012-11-15 23:02:16.071250 [DEBUG] mod_spandsp.c:648 Adding tone_descriptor: 49, tone: REORDER_TONE(2)
freeswitch@internal> 

2012-11-15 23:02:16.071250 [DEBUG] mod_spandsp.c:683 Adding tone_descriptor: 49, tone: REORDER_TONE(2), element (425, 0, 224, 272)
freeswitch@internal> 

2012-11-15 23:02:16.071250 [DEBUG] mod_spandsp.c:683 Adding tone_descriptor: 49, tone: REORDER_TONE(2), element (0, 0, 224, 272)
freeswitch@internal> 

2012-11-15 23:02:16.071250 [DEBUG] mod_spandsp.c:648 Adding tone_descriptor: 49, tone: BUSY_TONE(3)
freeswitch@internal> 

2012-11-15 23:02:16.071250 [DEBUG] mod_spandsp.c:683 Adding tone_descriptor: 49, tone: BUSY_TONE(3), element (425, 0, 464, 516)
freeswitch@internal> 

2012-11-15 23:02:16.071250 [DEBUG] mod_spandsp.c:683 Adding tone_descriptor: 49, tone: BUSY_TONE(3), element (0, 0, 464, 516)
freeswitch@internal> 

2012-11-15 23:02:16.071250 [INFO] switch_time.c:1163 Timezone reloaded 530 definitions
freeswitch@internal> 

freeswitch@internal> 
freeswitch@internal> 
freeswitch@internal> 
freeswitch@internal> 
freeswitch@internal> 
freeswitch@internal> 
freeswitch@internal> 
freeswitch@internal> 
freeswitch@internal> 
freeswitch@internal> 
freeswitch@internal> 
freeswitch@internal> 
freeswitch@internal> 
freeswitch@internal> 
freeswitch@internal> 
freeswitch@internal> sofdiia status
                     Name	   Type	                                      Data	State
=================================================================================================
                 internal	profile	          sip:mod_sofia@86.149.18.171:5060	RUNNING (0)
                 external	profile	          sip:mod_sofia@86.149.18.171:5080	RUNNING (0)
         external::bt-new	gateway	           sip:05603483043@bmnhb-03.bt.com	REGED
external::Sipgate_1216676494	gateway	                 sip:1542681@sipgate.co.uk	REGED
external::192.168.1.89-Sipgate_1216676494	gateway	                 sip:1542681@sipgate.co.uk	REGED
             192.168.1.89	  alias	                                  internal	ALIASED
            internal-ipv6	profile	                  sip:mod_sofia@[::1]:5060	RUNNING (0)
=================================================================================================
3 profiles 1 alias

freeswitch@internal> 
freeswitch@internal> 
2012-11-15 23:02:40.691255 [DEBUG] sofia_reg.c:2009 Changing expire time to 800 by request of proxy sip:bmnhb-03.bt.com
freeswitch@internal> 

freeswitch@internal> 
freeswitch@internal> 
freeswitch@internal> 
freeswitch@internal> 
freeswitch@internal> 
freeswitch@internal> 
freeswitch@internal> 
freeswitch@internal> 
2012-11-15 23:04:58.351275 [DEBUG] sofia.c:8042 IP 192.168.1.83 Rejected by acl "domains". Falling back to Digest auth.
freeswitch@internal> 

2012-11-15 23:04:58.351275 [WARNING] sofia_reg.c:1474 SIP auth challenge (INVITE) on sofia profile 'internal' for [901908321682@192.168.1.89] from ip 192.168.1.83
freeswitch@internal> 

2012-11-15 23:04:58.351275 [DEBUG] sofia.c:8042 IP 192.168.1.83 Rejected by acl "domains". Falling back to Digest auth.
freeswitch@internal> 

2012-11-15 23:04:58.351275 [NOTICE] switch_channel.c:930 New Channel sofia/internal/1234@192.168.1.89 [e057d62e-2f78-11e2-a4c2-e77d52f903ec]
freeswitch@internal> 

2012-11-15 23:04:58.351275 [DEBUG] switch_core_state_machine.c:385 (sofia/internal/1234@192.168.1.89) Running State Change CS_NEW
freeswitch@internal> 

2012-11-15 23:04:58.351275 [DEBUG] switch_core_state_machine.c:403 (sofia/internal/1234@192.168.1.89) State NEW
freeswitch@internal> 

2012-11-15 23:04:58.351275 [DEBUG] sofia.c:5931 Channel sofia/internal/1234@192.168.1.89 entering state [received][100]
freeswitch@internal> 

2012-11-15 23:04:58.351275 [DEBUG] sofia.c:5942 Remote SDP:
v=0o=- 3562009479 3562009479 IN IP4 192.168.1.83s=pjmediac=IN IP4 192.168.1.83t=0 0a=X-nat:0m=audio 4004 RTP/AVP 8 0 18 4 101a=rtpmap:8 PCMA/8000a=rtpmap:0 PCMU/8000a=rtpmap:18 G729/8000a=rtpmap:4 G723/8000a=rtpmap:101 telephone-event/8000a=fmtp:101 0-15a=rtcp:4005 IN IP4 192.168.1.83
freeswitch@internal> 

2012-11-15 23:04:58.351275 [DEBUG] sofia_glue.c:3948 Looking for zrtp-hash
freeswitch@internal> 

2012-11-15 23:04:58.351275 [DEBUG] sofia_glue.c:3926 Deciding whether to pass zrtp-hash between legs
freeswitch@internal> 

2012-11-15 23:04:58.351275 [DEBUG] sofia_glue.c:3928 CF_ZRTP_PASSTHRU_REQ not set, so not propagating zrtp-hash
freeswitch@internal> 

2012-11-15 23:04:58.351275 [DEBUG] sofia_glue.c:5044 Audio Codec Compare [PCMA:8:8000:20:64000]/[G722:9:8000:20:64000]
freeswitch@internal> 

2012-11-15 23:04:58.351275 [DEBUG] sofia_glue.c:5044 Audio Codec Compare [PCMA:8:8000:20:64000]/[PCMU:0:8000:20:64000]
freeswitch@internal> 

2012-11-15 23:04:58.351275 [DEBUG] sofia_glue.c:5044 Audio Codec Compare [PCMA:8:8000:20:64000]/[PCMA:8:8000:20:64000]
freeswitch@internal> 

2012-11-15 23:04:58.351275 [DEBUG] sofia_glue.c:3027 Set Codec sofia/internal/1234@192.168.1.89 PCMA/8000 20 ms 160 samples 64000 bits
freeswitch@internal> 

2012-11-15 23:04:58.351275 [DEBUG] switch_core_codec.c:111 sofia/internal/1234@192.168.1.89 Original read codec set to PCMA:8
freeswitch@internal> 

2012-11-15 23:04:58.351275 [DEBUG] sofia_glue.c:5165 Set 2833 dtmf send/recv payload to 101
freeswitch@internal> 

2012-11-15 23:04:58.351275 [DEBUG] sofia.c:6170 (sofia/internal/1234@192.168.1.89) State Change CS_NEW -> CS_INIT
freeswitch@internal> 

2012-11-15 23:04:58.351275 [DEBUG] switch_core_session.c:1229 Send signal sofia/internal/1234@192.168.1.89 [BREAK]
freeswitch@internal> 

2012-11-15 23:04:58.371327 [DEBUG] switch_core_state_machine.c:385 (sofia/internal/1234@192.168.1.89) Running State Change CS_INIT
freeswitch@internal> 

2012-11-15 23:04:58.371327 [DEBUG] switch_core_state_machine.c:424 (sofia/internal/1234@192.168.1.89) State INIT
freeswitch@internal> 

2012-11-15 23:04:58.371327 [DEBUG] mod_sofia.c:85 sofia/internal/1234@192.168.1.89 SOFIA INIT
freeswitch@internal> 

2012-11-15 23:04:58.371327 [DEBUG] mod_sofia.c:125 (sofia/internal/1234@192.168.1.89) State Change CS_INIT -> CS_ROUTING
freeswitch@internal> 

2012-11-15 23:04:58.371327 [DEBUG] switch_core_session.c:1229 Send signal sofia/internal/1234@192.168.1.89 [BREAK]
freeswitch@internal> 

2012-11-15 23:04:58.371327 [DEBUG] switch_core_state_machine.c:424 (sofia/internal/1234@192.168.1.89) State INIT going to sleep
freeswitch@internal> 

2012-11-15 23:04:58.371327 [DEBUG] switch_core_state_machine.c:385 (sofia/internal/1234@192.168.1.89) Running State Change CS_ROUTING
freeswitch@internal> 

2012-11-15 23:04:58.371327 [DEBUG] switch_channel.c:1923 (sofia/internal/1234@192.168.1.89) Callstate Change DOWN -> RINGING
freeswitch@internal> 

2012-11-15 23:04:58.371327 [DEBUG] switch_core_state_machine.c:433 (sofia/internal/1234@192.168.1.89) State ROUTING
freeswitch@internal> 

2012-11-15 23:04:58.371327 [DEBUG] mod_sofia.c:148 sofia/internal/1234@192.168.1.89 SOFIA ROUTING
freeswitch@internal> 

2012-11-15 23:04:58.371327 [DEBUG] switch_core_state_machine.c:104 sofia/internal/1234@192.168.1.89 Standard ROUTING
freeswitch@internal> 

2012-11-15 23:04:58.371327 [INFO] mod_dialplan_xml.c:485 Processing 1234 <1234>->901908321682 in context default
freeswitch@internal> 

Dialplan: sofia/internal/1234@192.168.1.89 parsing [default->Sipgate_1216676494.9.11d] continue=false
freeswitch@internal> 

Dialplan: sofia/internal/1234@192.168.1.89 Regex (PASS) [Sipgate_1216676494.9.11d] destination_number(901908321682) =~ /^9(\d{11})$/ break=on-false
freeswitch@internal> 

Dialplan: sofia/internal/1234@192.168.1.89 Action set(sip_h_X-accountcode=${accountcode}) 
freeswitch@internal> 

Dialplan: sofia/internal/1234@192.168.1.89 Action set(call_direction=outbound) 
freeswitch@internal> 

Dialplan: sofia/internal/1234@192.168.1.89 Action set(hangup_after_bridge=true) 
freeswitch@internal> 

Dialplan: sofia/internal/1234@192.168.1.89 Action set(effective_caller_id_name=${outbound_caller_id_name}) 
freeswitch@internal> 

Dialplan: sofia/internal/1234@192.168.1.89 Action set(effective_caller_id_number=${outbound_caller_id_number}) 
freeswitch@internal> 

Dialplan: sofia/internal/1234@192.168.1.89 Action set(inherit_codec=true) 
freeswitch@internal> 

Dialplan: sofia/internal/1234@192.168.1.89 Action bridge(sofia/gateway/bt-new/01908321682) 
freeswitch@internal> 

2012-11-15 23:04:58.371327 [DEBUG] switch_core_state_machine.c:154 (sofia/internal/1234@192.168.1.89) State Change CS_ROUTING -> CS_EXECUTE
freeswitch@internal> 

2012-11-15 23:04:58.371327 [DEBUG] switch_core_session.c:1229 Send signal sofia/internal/1234@192.168.1.89 [BREAK]
freeswitch@internal> 

2012-11-15 23:04:58.371327 [DEBUG] switch_core_state_machine.c:433 (sofia/internal/1234@192.168.1.89) State ROUTING going to sleep
freeswitch@internal> 

2012-11-15 23:04:58.371327 [DEBUG] switch_core_state_machine.c:385 (sofia/internal/1234@192.168.1.89) Running State Change CS_EXECUTE
freeswitch@internal> 

2012-11-15 23:04:58.371327 [DEBUG] switch_core_state_machine.c:440 (sofia/internal/1234@192.168.1.89) State EXECUTE
freeswitch@internal> 

2012-11-15 23:04:58.371327 [DEBUG] mod_sofia.c:241 sofia/internal/1234@192.168.1.89 SOFIA EXECUTE
freeswitch@internal> 

2012-11-15 23:04:58.371327 [DEBUG] switch_core_state_machine.c:196 sofia/internal/1234@192.168.1.89 Standard EXECUTE
freeswitch@internal> 

EXECUTE sofia/internal/1234@192.168.1.89 set(sip_h_X-accountcode=)
freeswitch@internal> 

2012-11-15 23:04:58.371327 [DEBUG] mod_dptools.c:1319 sofia/internal/1234@192.168.1.89 SET [sip_h_X-accountcode]=[UNDEF]
freeswitch@internal> 

EXECUTE sofia/internal/1234@192.168.1.89 set(call_direction=outbound)
freeswitch@internal> 

2012-11-15 23:04:58.371327 [DEBUG] mod_dptools.c:1319 sofia/internal/1234@192.168.1.89 SET [call_direction]=[outbound]
freeswitch@internal> 

EXECUTE sofia/internal/1234@192.168.1.89 set(hangup_after_bridge=true)
freeswitch@internal> 

2012-11-15 23:04:58.371327 [DEBUG] mod_dptools.c:1319 sofia/internal/1234@192.168.1.89 SET [hangup_after_bridge]=[true]
freeswitch@internal> 

EXECUTE sofia/internal/1234@192.168.1.89 set(effective_caller_id_name=)
freeswitch@internal> 

2012-11-15 23:04:58.371327 [DEBUG] mod_dptools.c:1319 sofia/internal/1234@192.168.1.89 SET [effective_caller_id_name]=[UNDEF]
freeswitch@internal> 

EXECUTE sofia/internal/1234@192.168.1.89 set(effective_caller_id_number=)
freeswitch@internal> 

2012-11-15 23:04:58.371327 [DEBUG] mod_dptools.c:1319 sofia/internal/1234@192.168.1.89 SET [effective_caller_id_number]=[UNDEF]
freeswitch@internal> 

EXECUTE sofia/internal/1234@192.168.1.89 set(inherit_codec=true)
freeswitch@internal> 

2012-11-15 23:04:58.371327 [DEBUG] mod_dptools.c:1319 sofia/internal/1234@192.168.1.89 SET [inherit_codec]=[true]
freeswitch@internal> 

EXECUTE sofia/internal/1234@192.168.1.89 bridge(sofia/gateway/bt-new/01908321682)
freeswitch@internal> 

2012-11-15 23:04:58.371327 [DEBUG] switch_channel.c:1051 sofia/internal/1234@192.168.1.89 EXPORTING[export_vars] [domain_name]=[192.168.1.89] to event
freeswitch@internal> 

2012-11-15 23:04:58.371327 [DEBUG] switch_ivr_originate.c:1961 Parsing global variables
freeswitch@internal> 

2012-11-15 23:04:58.371327 [NOTICE] switch_channel.c:930 New Channel sofia/external/01908321682 [e058d060-2f78-11e2-a4cd-e77d52f903ec]
freeswitch@internal> 

2012-11-15 23:04:58.371327 [DEBUG] mod_sofia.c:4774 (sofia/external/01908321682) State Change CS_NEW -> CS_INIT
freeswitch@internal> 

2012-11-15 23:04:58.371327 [DEBUG] switch_core_session.c:1229 Send signal sofia/external/01908321682 [BREAK]
freeswitch@internal> 

2012-11-15 23:04:58.371327 [DEBUG] switch_core_state_machine.c:385 (sofia/external/01908321682) Running State Change CS_INIT
freeswitch@internal> 

2012-11-15 23:04:58.371327 [DEBUG] switch_core_state_machine.c:424 (sofia/external/01908321682) State INIT
freeswitch@internal> 

2012-11-15 23:04:58.371327 [DEBUG] mod_sofia.c:85 sofia/external/01908321682 SOFIA INIT
freeswitch@internal> 

2012-11-15 23:04:58.371327 [INFO] switch_nat.c:590 NAT port mapping disabled
freeswitch@internal> 

2012-11-15 23:04:58.371327 [INFO] switch_nat.c:590 NAT port mapping disabled
freeswitch@internal> 

2012-11-15 23:04:58.731281 [DEBUG] sofia_glue.c:1018 STUN Success [86.149.18.171]:[20498]
freeswitch@internal> 

2012-11-15 23:04:58.731281 [DEBUG] sofia_glue.c:2580 sip:www.bbvservice-560348.bt.com Setting proxy route to sofia/external/01908321682
freeswitch@internal> 

2012-11-15 23:04:58.731281 [DEBUG] sofia_glue.c:2609 Local SDP:
v=0
o=FreeSWITCH 1353000200 1353000201 IN IP4 86.149.18.171
s=FreeSWITCH
c=IN IP4 86.149.18.171
t=0 0
m=audio 20498 RTP/AVP 8 0 3 101 13
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv

freeswitch@internal> 

2012-11-15 23:04:58.731281 [DEBUG] mod_sofia.c:125 (sofia/external/01908321682) State Change CS_INIT -> CS_ROUTING
freeswitch@internal> 

2012-11-15 23:04:58.731281 [DEBUG] switch_core_session.c:1229 Send signal sofia/external/01908321682 [BREAK]
freeswitch@internal> 

2012-11-15 23:04:58.731281 [DEBUG] switch_core_state_machine.c:424 (sofia/external/01908321682) State INIT going to sleep
freeswitch@internal> 

2012-11-15 23:04:58.731281 [DEBUG] switch_core_state_machine.c:385 (sofia/external/01908321682) Running State Change CS_ROUTING
freeswitch@internal> 

2012-11-15 23:04:58.731281 [DEBUG] switch_channel.c:1923 (sofia/external/01908321682) Callstate Change DOWN -> RINGING
freeswitch@internal> 

2012-11-15 23:04:58.731281 [DEBUG] switch_core_state_machine.c:433 (sofia/external/01908321682) State ROUTING
freeswitch@internal> 

2012-11-15 23:04:58.731281 [DEBUG] mod_sofia.c:148 sofia/external/01908321682 SOFIA ROUTING
freeswitch@internal> 

2012-11-15 23:04:58.731281 [DEBUG] switch_ivr_originate.c:67 (sofia/external/01908321682) State Change CS_ROUTING -> CS_CONSUME_MEDIA
freeswitch@internal> 

2012-11-15 23:04:58.731281 [DEBUG] switch_core_session.c:1229 Send signal sofia/external/01908321682 [BREAK]
freeswitch@internal> 

2012-11-15 23:04:58.731281 [DEBUG] switch_core_state_machine.c:433 (sofia/external/01908321682) State ROUTING going to sleep
freeswitch@internal> 

2012-11-15 23:04:58.731281 [DEBUG] switch_core_state_machine.c:385 (sofia/external/01908321682) Running State Change CS_CONSUME_MEDIA
freeswitch@internal> 

2012-11-15 23:04:58.731281 [DEBUG] switch_core_state_machine.c:452 (sofia/external/01908321682) State CONSUME_MEDIA
freeswitch@internal> 

2012-11-15 23:04:58.731281 [DEBUG] switch_core_state_machine.c:452 (sofia/external/01908321682) State CONSUME_MEDIA going to sleep
freeswitch@internal> 

2012-11-15 23:04:58.731281 [DEBUG] switch_core_session.c:924 Send signal sofia/external/01908321682 [BREAK]
freeswitch@internal> 

2012-11-15 23:04:58.731281 [DEBUG] sofia.c:5931 Channel sofia/external/01908321682 entering state [calling][0]
freeswitch@internal> 

2012-11-15 23:04:58.831294 [DEBUG] switch_core_session.c:924 Send signal sofia/external/01908321682 [BREAK]
freeswitch@internal> 

2012-11-15 23:04:58.831294 [DEBUG] switch_core_session.c:924 Send signal sofia/external/01908321682 [BREAK]
freeswitch@internal> 

2012-11-15 23:04:58.831294 [DEBUG] sofia.c:5931 Channel sofia/external/01908321682 entering state [calling][0]
freeswitch@internal> 

2012-11-15 23:04:59.731275 [DEBUG] switch_core_session.c:924 Send signal sofia/external/01908321682 [BREAK]
freeswitch@internal> 

2012-11-15 23:04:59.731275 [DEBUG] switch_core_session.c:924 Send signal sofia/external/01908321682 [BREAK]
freeswitch@internal> 

2012-11-15 23:04:59.731275 [DEBUG] sofia.c:5931 Channel sofia/external/01908321682 entering state [proceeding][183]
freeswitch@internal> 

2012-11-15 23:04:59.731275 [DEBUG] sofia.c:5942 Remote SDP:
v=0o=- 106001177 106001177 IN IP4 62.239.15.136s=-c=IN IP4 62.239.15.136t=0 0m=audio 32470 RTP/AVP 8 101a=rtpmap:101 telephone-event/8000a=ptime:20
freeswitch@internal> 

2012-11-15 23:04:59.731275 [DEBUG] sofia_glue.c:3948 Looking for zrtp-hash
freeswitch@internal> 

2012-11-15 23:04:59.731275 [DEBUG] sofia_glue.c:3926 Deciding whether to pass zrtp-hash between legs
freeswitch@internal> 

2012-11-15 23:04:59.731275 [DEBUG] sofia_glue.c:3928 CF_ZRTP_PASSTHRU_REQ not set, so not propagating zrtp-hash
freeswitch@internal> 

2012-11-15 23:04:59.731275 [DEBUG] sofia_glue.c:3948 Looking for zrtp-hash
freeswitch@internal> 

2012-11-15 23:04:59.731275 [DEBUG] sofia_glue.c:3926 Deciding whether to pass zrtp-hash between legs
freeswitch@internal> 

2012-11-15 23:04:59.731275 [DEBUG] sofia_glue.c:3928 CF_ZRTP_PASSTHRU_REQ not set, so not propagating zrtp-hash
freeswitch@internal> 

2012-11-15 23:04:59.731275 [DEBUG] sofia_glue.c:5044 Audio Codec Compare [PCMA:8:8000:20:64000]/[PCMA:8:8000:20:64000]
freeswitch@internal> 

2012-11-15 23:04:59.731275 [DEBUG] sofia_glue.c:3027 Set Codec sofia/external/01908321682 PCMA/8000 20 ms 160 samples 64000 bits
freeswitch@internal> 

2012-11-15 23:04:59.731275 [DEBUG] switch_core_codec.c:111 sofia/external/01908321682 Original read codec set to PCMA:8
freeswitch@internal> 

2012-11-15 23:04:59.731275 [DEBUG] sofia_glue.c:5158 Set 2833 dtmf send payload to 101
freeswitch@internal> 

2012-11-15 23:04:59.731275 [DEBUG] sofia_glue.c:3276 AUDIO RTP [sofia/external/01908321682] 192.168.1.89 port 20498 -> 62.239.15.136 port 32470 codec: 8 ms: 20
freeswitch@internal> 

2012-11-15 23:04:59.731275 [DEBUG] switch_rtp.c:1927 Starting timer [soft] 160 bytes per 20ms
freeswitch@internal> 

2012-11-15 23:04:59.731275 [DEBUG] sofia_glue.c:3540 Set 2833 dtmf send payload to 101
freeswitch@internal> 

2012-11-15 23:04:59.731275 [DEBUG] sofia_glue.c:3546 Set 2833 dtmf receive payload to 101
freeswitch@internal> 

2012-11-15 23:04:59.731275 [DEBUG] sofia_glue.c:3573 sofia/external/01908321682 Set rtp dtmf delay to 40
freeswitch@internal> 

2012-11-15 23:04:59.731275 [NOTICE] sofia_glue.c:4176 Pre-Answer sofia/external/01908321682!
freeswitch@internal> 

2012-11-15 23:04:59.731275 [DEBUG] switch_channel.c:3046 (sofia/external/01908321682) Callstate Change RINGING -> EARLY
freeswitch@internal> 

2012-11-15 23:04:59.731275 [DEBUG] switch_ivr_originate.c:412 Codec string PCMA@8000h@20i not supported on sofia/internal/1234@192.168.1.89, skipping inheritance
freeswitch@internal> 

2012-11-15 23:04:59.731275 [DEBUG] switch_channel.c:3088 Send signal sofia/internal/1234@192.168.1.89 [BREAK]
freeswitch@internal> 

2012-11-15 23:04:59.731275 [INFO] switch_ivr_originate.c:3309 Sending early media
freeswitch@internal> 

2012-11-15 23:04:59.731275 [DEBUG] sofia_glue.c:3276 AUDIO RTP [sofia/internal/1234@192.168.1.89] 192.168.1.89 port 21658 -> 192.168.1.83 port 4004 codec: 8 ms: 20
freeswitch@internal> 

2012-11-15 23:04:59.731275 [DEBUG] switch_rtp.c:1927 Starting timer [soft] 160 bytes per 20ms
freeswitch@internal> 

2012-11-15 23:04:59.731275 [DEBUG] sofia_glue.c:3540 Set 2833 dtmf send payload to 101
freeswitch@internal> 

2012-11-15 23:04:59.731275 [DEBUG] sofia_glue.c:3546 Set 2833 dtmf receive payload to 101
freeswitch@internal> 

2012-11-15 23:04:59.731275 [DEBUG] sofia_glue.c:3573 sofia/internal/1234@192.168.1.89 Set rtp dtmf delay to 40
freeswitch@internal> 

2012-11-15 23:04:59.731275 [DEBUG] mod_sofia.c:2636 Ring SDP:
v=0
o=FreeSWITCH 1352999041 1352999042 IN IP4 192.168.1.89
s=FreeSWITCH
c=IN IP4 192.168.1.89
t=0 0
m=audio 21658 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=ptime:20
a=sendrecv

freeswitch@internal> 

2012-11-15 23:04:59.731275 [NOTICE] mod_sofia.c:2639 Pre-Answer sofia/internal/1234@192.168.1.89!
freeswitch@internal> 

2012-11-15 23:04:59.731275 [DEBUG] switch_channel.c:3046 (sofia/internal/1234@192.168.1.89) Callstate Change RINGING -> EARLY
freeswitch@internal> 

2012-11-15 23:04:59.731275 [DEBUG] switch_core_session.c:778 Send signal sofia/internal/1234@192.168.1.89 [BREAK]
freeswitch@internal> 

2012-11-15 23:04:59.731275 [DEBUG] switch_ivr_originate.c:3360 Originate Resulted in Success: [sofia/external/01908321682]
freeswitch@internal> 

2012-11-15 23:04:59.731275 [DEBUG] switch_core_session.c:924 Send signal sofia/internal/1234@192.168.1.89 [BREAK]
freeswitch@internal> 

2012-11-15 23:04:59.731275 [DEBUG] sofia.c:5924 Channel sofia/internal/1234@192.168.1.89 skipping state [early][183]
freeswitch@internal> 

2012-11-15 23:04:59.731275 [DEBUG] switch_core_session.c:778 Send signal sofia/external/01908321682 [BREAK]
freeswitch@internal> 

2012-11-15 23:04:59.731275 [DEBUG] switch_core_session.c:778 Send signal sofia/internal/1234@192.168.1.89 [BREAK]
freeswitch@internal> 

2012-11-15 23:04:59.731275 [DEBUG] switch_ivr_bridge.c:1359 (sofia/external/01908321682) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
freeswitch@internal> 

2012-11-15 23:04:59.731275 [DEBUG] switch_core_session.c:1229 Send signal sofia/external/01908321682 [BREAK]
freeswitch@internal> 

2012-11-15 23:04:59.731275 [DEBUG] switch_core_state_machine.c:385 (sofia/external/01908321682) Running State Change CS_EXCHANGE_MEDIA
freeswitch@internal> 

2012-11-15 23:04:59.731275 [DEBUG] switch_core_state_machine.c:443 (sofia/external/01908321682) State EXCHANGE_MEDIA
freeswitch@internal> 

2012-11-15 23:04:59.731275 [DEBUG] mod_sofia.c:646 SOFIA EXCHANGE_MEDIA
freeswitch@internal> 

2012-11-15 23:04:59.791319 [DEBUG] switch_rtp.c:3594 Correct ip/port confirmed.
freeswitch@internal> 

2012-11-15 23:04:59.811267 [DEBUG] switch_rtp.c:3594 Correct ip/port confirmed.
freeswitch@internal> 

2012-11-15 23:05:03.771270 [DEBUG] switch_core_session.c:924 Send signal sofia/external/01908321682 [BREAK]
freeswitch@internal> 

2012-11-15 23:05:03.771270 [DEBUG] switch_core_session.c:924 Send signal sofia/external/01908321682 [BREAK]
freeswitch@internal> 

2012-11-15 23:05:03.791255 [DEBUG] sofia.c:5931 Channel sofia/external/01908321682 entering state [completing][200]
freeswitch@internal> 

2012-11-15 23:05:03.791255 [DEBUG] sofia.c:5939 Duplicate SDP
v=0o=- 106001177 106001177 IN IP4 62.239.15.136s=-c=IN IP4 62.239.15.136t=0 0m=audio 32470 RTP/AVP 8 101a=rtpmap:101 telephone-event/8000a=ptime:20
freeswitch@internal> 

2012-11-15 23:05:03.791255 [DEBUG] switch_core_session.c:924 Send signal sofia/external/01908321682 [BREAK]
freeswitch@internal> 

2012-11-15 23:05:03.791255 [DEBUG] switch_core_session.c:924 Send signal sofia/external/01908321682 [BREAK]
freeswitch@internal> 

2012-11-15 23:05:03.811254 [DEBUG] sofia.c:5931 Channel sofia/external/01908321682 entering state [ready][200]
freeswitch@internal> 

2012-11-15 23:05:03.811254 [DEBUG] switch_channel.c:3305 (sofia/external/01908321682) Callstate Change EARLY -> ACTIVE
freeswitch@internal> 

2012-11-15 23:05:03.811254 [DEBUG] switch_channel.c:3317 Send signal sofia/internal/1234@192.168.1.89 [BREAK]
freeswitch@internal> 

2012-11-15 23:05:03.811254 [NOTICE] sofia.c:6607 Channel [sofia/external/01908321682] has been answered
freeswitch@internal> 

2012-11-15 23:05:03.831307 [DEBUG] mod_sofia.c:821 Local SDP sofia/internal/1234@192.168.1.89:
v=0
o=FreeSWITCH 1352999041 1352999043 IN IP4 192.168.1.89
s=FreeSWITCH
c=IN IP4 192.168.1.89
t=0 0
m=audio 21658 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=ptime:20
a=sendrecv

freeswitch@internal> 

2012-11-15 23:05:03.831307 [DEBUG] switch_core_session.c:778 Send signal sofia/internal/1234@192.168.1.89 [BREAK]
freeswitch@internal> 

2012-11-15 23:05:03.831307 [DEBUG] switch_channel.c:3305 (sofia/internal/1234@192.168.1.89) Callstate Change EARLY -> ACTIVE
freeswitch@internal> 

2012-11-15 23:05:03.831307 [NOTICE] switch_ivr_bridge.c:419 Channel [sofia/internal/1234@192.168.1.89] has been answered
freeswitch@internal> 

2012-11-15 23:05:03.831307 [DEBUG] switch_core_session.c:924 Send signal sofia/internal/1234@192.168.1.89 [BREAK]
freeswitch@internal> 

2012-11-15 23:05:03.831307 [DEBUG] sofia.c:5931 Channel sofia/internal/1234@192.168.1.89 entering state [completed][200]
freeswitch@internal> 

freeswitch@internal> 
freeswitch@internal> 
freeswitch@internal> 
freeswitch@internal> 
freeswitch@internal> 
freeswitch@internal> 
freeswitch@internal> 
freeswitch@internal> 
freeswitch@internal> 
freeswitch@internal> 
freeswitch@internal> 
freeswitch@internal> 
freeswitch@internal> 
freeswitch@internal> 
freeswitch@internal> 



             CALL IS CONNECTED AT THIS STAGE AND BOTH PARTIES ARE TALKING FINE FOR 15 seconds


freeswitch@internal> 
freeswitch@internal> 
freeswitch@internal> 
freeswitch@internal> 
freeswitch@internal> 
freeswitch@internal> 
freeswitch@internal> 
freeswitch@internal> 
freeswitch@internal> 
freeswitch@internal> 
freeswitch@internal> 
freeswitch@internal> 
freeswitch@internal> 
freeswitch@internal> 
freeswitch@internal> 
freeswitch@internal> 
freeswitch@internal> 
freeswitch@internal> 
freeswitch@internal> 
freeswitch@internal> 
2012-11-15 23:05:29.731263 [DEBUG] switch_core_session.c:924 Send signal sofia/external/01908321682 [BREAK]
freeswitch@internal> 

2012-11-15 23:05:29.731263 [DEBUG] switch_core_session.c:924 Send signal sofia/external/01908321682 [BREAK]
freeswitch@internal> 

2012-11-15 23:05:29.751264 [DEBUG] sofia.c:5931 Channel sofia/external/01908321682 entering state [received][100]
freeswitch@internal> 

2012-11-15 23:05:29.751264 [DEBUG] sofia.c:5939 Duplicate SDP
v=0o=- 106001177 106001177 IN IP4 62.239.15.136s=-c=IN IP4 62.239.15.136t=0 0m=audio 32470 RTP/AVP 8 101a=rtpmap:101 telephone-event/8000a=ptime:20
freeswitch@internal> 

2012-11-15 23:05:29.751264 [DEBUG] sofia_glue.c:3948 Looking for zrtp-hash
freeswitch@internal> 

2012-11-15 23:05:29.751264 [DEBUG] sofia_glue.c:3926 Deciding whether to pass zrtp-hash between legs
freeswitch@internal> 

2012-11-15 23:05:29.751264 [DEBUG] sofia_glue.c:3928 CF_ZRTP_PASSTHRU_REQ not set, so not propagating zrtp-hash
freeswitch@internal> 

2012-11-15 23:05:29.751264 [DEBUG] sofia_glue.c:5044 Audio Codec Compare [PCMA:8:8000:20:64000]/[PCMA:8:8000:20:64000]
freeswitch@internal> 

2012-11-15 23:05:29.751264 [DEBUG] sofia_glue.c:2961 Already using PCMA
freeswitch@internal> 

2012-11-15 23:05:29.751264 [DEBUG] sofia_glue.c:5158 Set 2833 dtmf send payload to 101
freeswitch@internal> 

2012-11-15 23:05:29.751264 [DEBUG] sofia_glue.c:3246 Audio params are unchanged for sofia/external/01908321682.
freeswitch@internal> 

2012-11-15 23:05:29.751264 [DEBUG] sofia_glue.c:3256 sofia/external/01908321682 Setting audio receive payload in Re-INVITE to 8
freeswitch@internal> 

2012-11-15 23:05:29.751264 [DEBUG] sofia.c:6466 Processing updated SDP
freeswitch@internal> 

2012-11-15 23:05:29.751264 [DEBUG] switch_core_session.c:924 Send signal sofia/external/01908321682 [BREAK]
freeswitch@internal> 

2012-11-15 23:05:29.771252 [DEBUG] sofia.c:5931 Channel sofia/external/01908321682 entering state [completed][200]
freeswitch@internal> 

2012-11-15 23:05:29.791250 [DEBUG] switch_core_session.c:924 Send signal sofia/external/01908321682 [BREAK]
freeswitch@internal> 

2012-11-15 23:05:29.791250 [DEBUG] switch_core_session.c:924 Send signal sofia/external/01908321682 [BREAK]
freeswitch@internal> 

2012-11-15 23:05:29.791250 [DEBUG] switch_core_session.c:924 Send signal sofia/external/01908321682 [BREAK]
freeswitch@internal> 

2012-11-15 23:05:29.811284 [DEBUG] sofia.c:5931 Channel sofia/external/01908321682 entering state [ready][200]
freeswitch@internal> 

2012-11-15 23:05:35.831320 [DEBUG] switch_core_session.c:924 Send signal sofia/internal/1234@192.168.1.89 [BREAK]
freeswitch@internal> 

2012-11-15 23:05:35.831320 [DEBUG] switch_core_session.c:924 Send signal sofia/internal/1234@192.168.1.89 [BREAK]
freeswitch@internal> 

2012-11-15 23:05:35.831320 [DEBUG] switch_core_session.c:924 Send signal sofia/internal/1234@192.168.1.89 [BREAK]
freeswitch@internal> 

2012-11-15 23:05:35.831320 [DEBUG] switch_core_session.c:924 Send signal sofia/internal/1234@192.168.1.89 [BREAK]
freeswitch@internal> 

2012-11-15 23:05:35.831320 [DEBUG] switch_core_session.c:924 Send signal sofia/internal/1234@192.168.1.89 [BREAK]
freeswitch@internal> 

2012-11-15 23:05:35.851294 [DEBUG] sofia.c:5931 Channel sofia/internal/1234@192.168.1.89 entering state [terminating][0]
freeswitch@internal> 

2012-11-15 23:05:35.851294 [DEBUG] switch_channel.c:2903 (sofia/internal/1234@192.168.1.89) Callstate Change ACTIVE -> HANGUP
freeswitch@internal> 

2012-11-15 23:05:35.851294 [NOTICE] sofia.c:6723 Hangup sofia/internal/1234@192.168.1.89 [CS_EXECUTE] [NORMAL_UNSPECIFIED]
freeswitch@internal> 

2012-11-15 23:05:35.851294 [DEBUG] switch_channel.c:2926 Send signal sofia/internal/1234@192.168.1.89 [KILL]
freeswitch@internal> 

2012-11-15 23:05:35.851294 [DEBUG] switch_core_session.c:1229 Send signal sofia/internal/1234@192.168.1.89 [BREAK]
freeswitch@internal> 

2012-11-15 23:05:35.851294 [DEBUG] switch_ivr_bridge.c:588 BRIDGE THREAD DONE [sofia/internal/1234@192.168.1.89]
freeswitch@internal> 

2012-11-15 23:05:35.851294 [DEBUG] switch_ivr_bridge.c:613 Send signal sofia/external/01908321682 [BREAK]
freeswitch@internal> 

2012-11-15 23:05:35.871275 [DEBUG] switch_ivr_bridge.c:501 sofia/internal/1234@192.168.1.89 ending bridge by request from write function
freeswitch@internal> 

2012-11-15 23:05:35.871275 [DEBUG] switch_ivr_bridge.c:588 BRIDGE THREAD DONE [sofia/external/01908321682]
freeswitch@internal> 

2012-11-15 23:05:35.871275 [DEBUG] switch_ivr_bridge.c:613 Send signal sofia/internal/1234@192.168.1.89 [BREAK]
freeswitch@internal> 

2012-11-15 23:05:35.871275 [DEBUG] switch_channel.c:2903 (sofia/external/01908321682) Callstate Change ACTIVE -> HANGUP
freeswitch@internal> 

2012-11-15 23:05:35.871275 [NOTICE] switch_ivr_bridge.c:676 Hangup sofia/external/01908321682 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING]
freeswitch@internal> 

2012-11-15 23:05:35.871275 [DEBUG] switch_channel.c:2926 Send signal sofia/external/01908321682 [KILL]
freeswitch@internal> 

2012-11-15 23:05:35.871275 [DEBUG] switch_core_session.c:1229 Send signal sofia/external/01908321682 [BREAK]
freeswitch@internal> 

2012-11-15 23:05:35.871275 [DEBUG] switch_core_state_machine.c:443 (sofia/external/01908321682) State EXCHANGE_MEDIA going to sleep
freeswitch@internal> 

2012-11-15 23:05:35.871275 [DEBUG] switch_core_state_machine.c:385 (sofia/external/01908321682) Running State Change CS_HANGUP
freeswitch@internal> 

2012-11-15 23:05:35.871275 [DEBUG] switch_core_state_machine.c:625 (sofia/external/01908321682) State HANGUP
freeswitch@internal> 

2012-11-15 23:05:35.871275 [DEBUG] mod_sofia.c:469 Channel sofia/external/01908321682 hanging up, cause: NORMAL_CLEARING
freeswitch@internal> 

2012-11-15 23:05:35.871275 [DEBUG] mod_sofia.c:518 Sending BYE to sofia/external/01908321682
freeswitch@internal> 

2012-11-15 23:05:35.871275 [DEBUG] switch_core_state_machine.c:47 sofia/external/01908321682 Standard HANGUP, cause: NORMAL_CLEARING
freeswitch@internal> 

2012-11-15 23:05:35.871275 [DEBUG] switch_core_state_machine.c:625 (sofia/external/01908321682) State HANGUP going to sleep
freeswitch@internal> 

2012-11-15 23:05:35.871275 [DEBUG] switch_core_state_machine.c:416 (sofia/external/01908321682) State Change CS_HANGUP -> CS_REPORTING
freeswitch@internal> 

2012-11-15 23:05:35.871275 [DEBUG] switch_core_session.c:1229 Send signal sofia/external/01908321682 [BREAK]
freeswitch@internal> 

2012-11-15 23:05:35.871275 [DEBUG] switch_core_state_machine.c:385 (sofia/external/01908321682) Running State Change CS_REPORTING
freeswitch@internal> 

2012-11-15 23:05:35.871275 [DEBUG] switch_core_state_machine.c:685 (sofia/external/01908321682) State REPORTING
freeswitch@internal> 

2012-11-15 23:05:35.871275 [DEBUG] switch_core_state_machine.c:79 sofia/external/01908321682 Standard REPORTING, cause: NORMAL_CLEARING
freeswitch@internal> 

2012-11-15 23:05:35.871275 [DEBUG] switch_core_state_machine.c:685 (sofia/external/01908321682) State REPORTING going to sleep
freeswitch@internal> 

2012-11-15 23:05:35.871275 [DEBUG] switch_ivr_bridge.c:1456 sofia/external/01908321682 skip receive message [UNBRIDGE] (channel is hungup already)
freeswitch@internal> 

2012-11-15 23:05:35.871275 [DEBUG] switch_ivr_bridge.c:1459 sofia/internal/1234@192.168.1.89 skip receive message [UNBRIDGE] (channel is hungup already)
freeswitch@internal> 

2012-11-15 23:05:35.871275 [DEBUG] switch_core_state_machine.c:410 (sofia/external/01908321682) State Change CS_REPORTING -> CS_DESTROY
freeswitch@internal> 

2012-11-15 23:05:35.871275 [DEBUG] switch_core_session.c:1229 Send signal sofia/external/01908321682 [BREAK]
freeswitch@internal> 

2012-11-15 23:05:35.871275 [DEBUG] switch_core_session.c:1429 Session 25 (sofia/external/01908321682) Locked, Waiting on external entities
freeswitch@internal> 

2012-11-15 23:05:35.871275 [NOTICE] switch_core_session.c:1447 Session 25 (sofia/external/01908321682) Ended
freeswitch@internal> 

2012-11-15 23:05:35.871275 [NOTICE] switch_core_session.c:1449 Close Channel sofia/external/01908321682 [CS_DESTROY]
freeswitch@internal> 

2012-11-15 23:05:35.871275 [DEBUG] switch_core_session.c:2345 sofia/internal/1234@192.168.1.89 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
freeswitch@internal> 

2012-11-15 23:05:35.871275 [DEBUG] switch_core_state_machine.c:440 (sofia/internal/1234@192.168.1.89) State EXECUTE going to sleep
freeswitch@internal> 

2012-11-15 23:05:35.871275 [DEBUG] switch_core_state_machine.c:385 (sofia/internal/1234@192.168.1.89) Running State Change CS_HANGUP
freeswitch@internal> 

2012-11-15 23:05:35.871275 [DEBUG] switch_core_state_machine.c:514 (sofia/external/01908321682) Callstate Change HANGUP -> DOWN
freeswitch@internal> 

2012-11-15 23:05:35.871275 [DEBUG] switch_core_state_machine.c:517 (sofia/external/01908321682) Running State Change CS_DESTROY
freeswitch@internal> 

2012-11-15 23:05:35.871275 [DEBUG] switch_core_state_machine.c:527 (sofia/external/01908321682) State DESTROY
freeswitch@internal> 

2012-11-15 23:05:35.871275 [DEBUG] mod_sofia.c:374 sofia/external/01908321682 SOFIA DESTROY
freeswitch@internal> 

2012-11-15 23:05:35.871275 [DEBUG] switch_core_state_machine.c:86 sofia/external/01908321682 Standard DESTROY
freeswitch@internal> 

2012-11-15 23:05:35.871275 [DEBUG] switch_core_state_machine.c:527 (sofia/external/01908321682) State DESTROY going to sleep
freeswitch@internal> 

2012-11-15 23:05:35.871275 [DEBUG] switch_core_state_machine.c:625 (sofia/internal/1234@192.168.1.89) State HANGUP
freeswitch@internal> 

2012-11-15 23:05:35.871275 [DEBUG] mod_sofia.c:469 Channel sofia/internal/1234@192.168.1.89 hanging up, cause: NORMAL_UNSPECIFIED
freeswitch@internal> 

2012-11-15 23:05:35.871275 [DEBUG] switch_core_state_machine.c:47 sofia/internal/1234@192.168.1.89 Standard HANGUP, cause: NORMAL_UNSPECIFIED
freeswitch@internal> 

2012-11-15 23:05:35.871275 [DEBUG] switch_core_state_machine.c:625 (sofia/internal/1234@192.168.1.89) State HANGUP going to sleep
freeswitch@internal> 

2012-11-15 23:05:35.871275 [DEBUG] switch_core_state_machine.c:416 (sofia/internal/1234@192.168.1.89) State Change CS_HANGUP -> CS_REPORTING
freeswitch@internal> 

2012-11-15 23:05:35.871275 [DEBUG] switch_core_session.c:1229 Send signal sofia/internal/1234@192.168.1.89 [BREAK]
freeswitch@internal> 

2012-11-15 23:05:35.871275 [DEBUG] switch_core_state_machine.c:385 (sofia/internal/1234@192.168.1.89) Running State Change CS_REPORTING
freeswitch@internal> 

2012-11-15 23:05:35.871275 [DEBUG] switch_core_state_machine.c:685 (sofia/internal/1234@192.168.1.89) State REPORTING
freeswitch@internal> 

2012-11-15 23:05:35.931266 [DEBUG] switch_core_state_machine.c:79 sofia/internal/1234@192.168.1.89 Standard REPORTING, cause: NORMAL_UNSPECIFIED
freeswitch@internal> 

2012-11-15 23:05:35.931266 [DEBUG] switch_core_state_machine.c:685 (sofia/internal/1234@192.168.1.89) State REPORTING going to sleep
freeswitch@internal> 

2012-11-15 23:05:35.931266 [DEBUG] switch_core_state_machine.c:410 (sofia/internal/1234@192.168.1.89) State Change CS_REPORTING -> CS_DESTROY
freeswitch@internal> 

2012-11-15 23:05:35.931266 [DEBUG] switch_core_session.c:1229 Send signal sofia/internal/1234@192.168.1.89 [BREAK]
freeswitch@internal> 

2012-11-15 23:05:35.931266 [DEBUG] switch_core_session.c:1429 Session 24 (sofia/internal/1234@192.168.1.89) Locked, Waiting on external entities
freeswitch@internal> 

2012-11-15 23:05:35.931266 [NOTICE] switch_core_session.c:1447 Session 24 (sofia/internal/1234@192.168.1.89) Ended
freeswitch@internal> 

2012-11-15 23:05:35.931266 [NOTICE] switch_core_session.c:1449 Close Channel sofia/internal/1234@192.168.1.89 [CS_DESTROY]
freeswitch@internal> 

2012-11-15 23:05:35.931266 [DEBUG] switch_core_state_machine.c:514 (sofia/internal/1234@192.168.1.89) Callstate Change HANGUP -> DOWN
freeswitch@internal> 

2012-11-15 23:05:35.931266 [DEBUG] switch_core_state_machine.c:517 (sofia/internal/1234@192.168.1.89) Running State Change CS_DESTROY
freeswitch@internal> 

2012-11-15 23:05:35.931266 [DEBUG] switch_core_state_machine.c:527 (sofia/internal/1234@192.168.1.89) State DESTROY
freeswitch@internal> 

2012-11-15 23:05:35.931266 [DEBUG] mod_sofia.c:374 sofia/internal/1234@192.168.1.89 SOFIA DESTROY
freeswitch@internal> 

2012-11-15 23:05:35.931266 [DEBUG] switch_core_state_machine.c:86 sofia/internal/1234@192.168.1.89 Standard DESTROY
freeswitch@internal> 

2012-11-15 23:05:35.931266 [DEBUG] switch_core_state_machine.c:527 (sofia/internal/1234@192.168.1.89) State DESTROY going to sleep
freeswitch@internal> 

freeswitch@internal> 
freeswitch@internal> 
freeswitch@internal> 
freeswitch@internal> 
freeswitch@internal> /quit
]0;root@TAS-FSwitch: ~root@TAS-FSwitch:~#