gistfile1.txt

freeswitch@internal> 2009-09-24 12:00:00.8122 [NOTICE] switch_channel.c:602 New Channel sofia/external/unknown@129.142.224.250 [c89c70c2-a901-11de-8545-e50cdff4e50a]
2009-09-24 12:00:00.8122 [DEBUG] sofia.c:3302 Channel sofia/external/unknown@129.142.224.250 entering state [received][100]
2009-09-24 12:00:00.8122 [DEBUG] sofia.c:3309 Remote SDP:
v=0
o=root 18982 18982 IN IP4 129.142.224.250
s=session
c=IN IP4 129.142.224.250
t=0 0
m=audio 11640 RTP/AVP 8 0 3 97
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:3 GSM/8000
a=rtpmap:97 iLBC/8000
a=fmtp:97 mode=30
a=silenceSupp:off - - - -
a=ptime:20

2009-09-24 12:00:00.8122 [DEBUG] sofia_glue.c:3132 Audio Codec Compare [PCMA:8:8000:20]/[PCMA:8:8000:20]
2009-09-24 12:00:00.8122 [DEBUG] sofia_glue.c:2090 Set Codec sofia/external/unknown@129.142.224.250 PCMA/8000 20 ms 160 samples
2009-09-24 12:00:00.8122 [DEBUG] sofia.c:3468 (sofia/external/unknown@129.142.224.250) State Change CS_NEW -> CS_INIT
2009-09-24 12:00:00.8122 [DEBUG] switch_core_session.c:932 Send signal sofia/external/unknown@129.142.224.250 [BREAK]
2009-09-24 12:00:00.8122 [DEBUG] switch_core_state_machine.c:398 (sofia/external/unknown@129.142.224.250) Running State Change CS_INIT
2009-09-24 12:00:00.8122 [DEBUG] switch_core_state_machine.c:481 (sofia/external/unknown@129.142.224.250) State INIT
2009-09-24 12:00:00.8122 [DEBUG] mod_sofia.c:83 sofia/external/unknown@129.142.224.250 SOFIA INIT
2009-09-24 12:00:00.8122 [DEBUG] mod_sofia.c:111 (sofia/external/unknown@129.142.224.250) State Change CS_INIT -> CS_ROUTING
2009-09-24 12:00:00.8122 [DEBUG] switch_core_session.c:932 Send signal sofia/external/unknown@129.142.224.250 [BREAK]
2009-09-24 12:00:00.8122 [DEBUG] switch_core_state_machine.c:481 (sofia/external/unknown@129.142.224.250) State INIT going to sleep
2009-09-24 12:00:00.8122 [DEBUG] switch_core_state_machine.c:398 (sofia/external/unknown@129.142.224.250) Running State Change CS_ROUTING
2009-09-24 12:00:00.8122 [DEBUG] switch_core_state_machine.c:484 (sofia/external/unknown@129.142.224.250) State ROUTING
2009-09-24 12:00:00.8122 [DEBUG] mod_sofia.c:130 sofia/external/unknown@129.142.224.250 SOFIA ROUTING
2009-09-24 12:00:00.8122 [DEBUG] switch_core_state_machine.c:78 sofia/external/unknown@129.142.224.250 Standard ROUTING
2009-09-24 12:00:00.8122 [INFO] mod_dialplan_xml.c:315 Processing unknown->77344540 in context public
Dialplan: sofia/external/unknown@129.142.224.250 parsing [public->ff-ivr] continue=false
Dialplan: sofia/external/unknown@129.142.224.250 Regex (PASS) [ff-ivr] destination_number(77344540) =~ /^(\d+)$/ break=on-false
Dialplan: sofia/external/unknown@129.142.224.250 Action set(bypass_media=false)
Dialplan: sofia/external/unknown@129.142.224.250 Action socket(127.0.0.1:8084 full)
2009-09-24 12:00:00.8122 [DEBUG] switch_core_state_machine.c:114 (sofia/external/unknown@129.142.224.250) State Change CS_ROUTING -> CS_EXECUTE
2009-09-24 12:00:00.8122 [DEBUG] switch_core_session.c:932 Send signal sofia/external/unknown@129.142.224.250 [BREAK]
2009-09-24 12:00:00.8122 [DEBUG] switch_core_state_machine.c:484 (sofia/external/unknown@129.142.224.250) State ROUTING going to sleep
2009-09-24 12:00:00.8122 [DEBUG] switch_core_state_machine.c:398 (sofia/external/unknown@129.142.224.250) Running State Change CS_EXECUTE
2009-09-24 12:00:00.8122 [DEBUG] switch_core_state_machine.c:491 (sofia/external/unknown@129.142.224.250) State EXECUTE
2009-09-24 12:00:00.8122 [DEBUG] mod_sofia.c:173 sofia/external/unknown@129.142.224.250 SOFIA EXECUTE
2009-09-24 12:00:00.8122 [DEBUG] switch_core_state_machine.c:151 sofia/external/unknown@129.142.224.250 Standard EXECUTE
EXECUTE sofia/external/unknown@129.142.224.250 set(bypass_media=false)
2009-09-24 12:00:00.8122 [DEBUG] mod_dptools.c:748 sofia/external/unknown@129.142.224.250 SET [bypass_media]=[false]
EXECUTE sofia/external/unknown@129.142.224.250 socket(127.0.0.1:8084 full)
2009-09-24 12:00:00.304949 [DEBUG] switch_ivr.c:540 sofia/external/unknown@129.142.224.250 Command Execute set(hold_music=silence)
EXECUTE sofia/external/unknown@129.142.224.250 set(hold_music=silence)
2009-09-24 12:00:00.304949 [DEBUG] mod_dptools.c:748 sofia/external/unknown@129.142.224.250 SET [hold_music]=[silence]
2009-09-24 12:00:00.304949 [DEBUG] switch_ivr.c:540 sofia/external/unknown@129.142.224.250 Command Execute set(effective_caller_id_number=77344540)
EXECUTE sofia/external/unknown@129.142.224.250 set(effective_caller_id_number=77344540)
2009-09-24 12:00:00.304949 [DEBUG] mod_dptools.c:748 sofia/external/unknown@129.142.224.250 SET [effective_caller_id_number]=[77344540]
2009-09-24 12:00:00.304949 [DEBUG] switch_ivr.c:540 sofia/external/unknown@129.142.224.250 Command Execute set(hangup_after_bridge=true)
EXECUTE sofia/external/unknown@129.142.224.250 set(hangup_after_bridge=true)
2009-09-24 12:00:00.304949 [DEBUG] mod_dptools.c:748 sofia/external/unknown@129.142.224.250 SET [hangup_after_bridge]=[true]
2009-09-24 12:00:00.304949 [DEBUG] switch_ivr.c:540 sofia/external/unknown@129.142.224.250 Command Execute set(ignore_early_media=true)
EXECUTE sofia/external/unknown@129.142.224.250 set(ignore_early_media=true)
2009-09-24 12:00:00.304949 [DEBUG] mod_dptools.c:748 sofia/external/unknown@129.142.224.250 SET [ignore_early_media]=[true]
2009-09-24 12:00:00.304949 [DEBUG] switch_ivr.c:540 sofia/external/unknown@129.142.224.250 Command Execute set(bypass_media=false)
EXECUTE sofia/external/unknown@129.142.224.250 set(bypass_media=false)
2009-09-24 12:00:00.304949 [DEBUG] mod_dptools.c:748 sofia/external/unknown@129.142.224.250 SET [bypass_media]=[false]
2009-09-24 12:00:00.304949 [DEBUG] switch_ivr.c:540 sofia/external/unknown@129.142.224.250 Command Execute set(ringback=%(2000,4000,440,480))
EXECUTE sofia/external/unknown@129.142.224.250 set(ringback=%(2000,4000,440,480))
2009-09-24 12:00:00.304949 [DEBUG] mod_dptools.c:748 sofia/external/unknown@129.142.224.250 SET [ringback]=[%(2000,4000,440,480)]
2009-09-24 12:00:00.304949 [DEBUG] switch_ivr.c:540 sofia/external/unknown@129.142.224.250 Command Execute set(instant_ringback=true)
EXECUTE sofia/external/unknown@129.142.224.250 set(instant_ringback=true)
2009-09-24 12:00:00.304949 [DEBUG] mod_dptools.c:748 sofia/external/unknown@129.142.224.250 SET [instant_ringback]=[true]
2009-09-24 12:00:00.304949 [DEBUG] switch_ivr.c:540 sofia/external/unknown@129.142.224.250 Command Execute bind_meta_app(5 b a transfer::ff-transfer-sofia/gateway/gw1.fonet.dk/99400799 XML public)
EXECUTE sofia/external/unknown@129.142.224.250 bind_meta_app(5 b a transfer::ff-transfer-sofia/gateway/gw1.fonet.dk/99400799 XML public)
2009-09-24 12:00:00.304949 [INFO] switch_ivr_async.c:1809 Bound B-Leg: 5 transfer::ff-transfer-sofia/gateway/gw1.fonet.dk/99400799 XML public
2009-09-24 12:00:00.304949 [DEBUG] switch_ivr.c:540 sofia/external/unknown@129.142.224.250 Command Execute bind_meta_app(1 b a transfer::ff-transfer-sofia/gateway/gw1.fonet.dk/31354228 XML public)
EXECUTE sofia/external/unknown@129.142.224.250 bind_meta_app(1 b a transfer::ff-transfer-sofia/gateway/gw1.fonet.dk/31354228 XML public)
2009-09-24 12:00:00.304949 [INFO] switch_ivr_async.c:1809 Bound B-Leg: 1 transfer::ff-transfer-sofia/gateway/gw1.fonet.dk/31354228 XML public
2009-09-24 12:00:00.304949 [DEBUG] switch_ivr.c:540 sofia/external/unknown@129.142.224.250 Command Execute answer()
EXECUTE sofia/external/unknown@129.142.224.250 answer()
2009-09-24 12:00:00.304949 [DEBUG] mod_dptools.c:649 sofia/external/unknown@129.142.224.250 receive message [ANSWER]
2009-09-24 12:00:00.304949 [DEBUG] sofia_glue.c:2324 AUDIO RTP [sofia/external/unknown@129.142.224.250] 10.227.10.228 port 29152 -> 129.142.224.250 port 11640 codec: 8 ms: 20
2009-09-24 12:00:00.304949 [DEBUG] switch_rtp.c:1139 Starting timer [soft] 160 bytes per 20ms
2009-09-24 12:00:00.311236 [DEBUG] mod_sofia.c:536 Local SDP sofia/external/unknown@129.142.224.250:
v=0
o=FreeSWITCH 1253764448 1253764449 IN IP4 79.125.3.154
s=FreeSWITCH
c=IN IP4 79.125.3.154
t=0 0
m=audio 29152 RTP/AVP 8
a=rtpmap:8 PCMA/8000
a=silenceSupp:off - - - -
a=ptime:20
a=sendrecv

2009-09-24 12:00:00.311236 [DEBUG] switch_core_session.c:630 Send signal sofia/external/unknown@129.142.224.250 [BREAK]
2009-09-24 12:00:00.361345 [NOTICE] mod_dptools.c:649 Channel [sofia/external/unknown@129.142.224.250] has been answered
2009-09-24 12:00:00.361345 [DEBUG] switch_channel.c:182 sofia/external/unknown@129.142.224.250 receive message [AUDIO_SYNC]
2009-09-24 12:00:00.342299 [DEBUG] sofia.c:3302 Channel sofia/external/unknown@129.142.224.250 entering state [completed][200]
2009-09-24 12:00:00.382797 [DEBUG] switch_ivr.c:540 sofia/external/unknown@129.142.224.250 Command Execute bridge(sofia/gateway/gw1.fonet.dk/31354228)
EXECUTE sofia/external/unknown@129.142.224.250 bridge(sofia/gateway/gw1.fonet.dk/31354228)
2009-09-24 12:00:00.382797 [NOTICE] switch_channel.c:602 New Channel sofia/external/31354228 [c8d552c0-a901-11de-8545-e50cdff4e50a]
2009-09-24 12:00:00.382797 [DEBUG] mod_sofia.c:2867 (sofia/external/31354228) State Change CS_NEW -> CS_INIT
2009-09-24 12:00:00.382797 [DEBUG] switch_core_session.c:932 Send signal sofia/external/31354228 [BREAK]
2009-09-24 12:00:00.382797 [DEBUG] switch_core_state_machine.c:398 (sofia/external/31354228) Running State Change CS_INIT
2009-09-24 12:00:00.382797 [DEBUG] switch_core_state_machine.c:481 (sofia/external/31354228) State INIT
2009-09-24 12:00:00.382797 [DEBUG] mod_sofia.c:83 sofia/external/31354228 SOFIA INIT
2009-09-24 12:00:00.382797 [DEBUG] mod_sofia.c:111 (sofia/external/31354228) State Change CS_INIT -> CS_ROUTING
2009-09-24 12:00:00.382797 [DEBUG] switch_core_session.c:932 Send signal sofia/external/31354228 [BREAK]
2009-09-24 12:00:00.382797 [DEBUG] sofia.c:3302 Channel sofia/external/31354228 entering state [calling][0]
2009-09-24 12:00:00.382797 [DEBUG] switch_core_state_machine.c:481 (sofia/external/31354228) State INIT going to sleep
2009-09-24 12:00:00.382797 [DEBUG] switch_core_state_machine.c:398 (sofia/external/31354228) Running State Change CS_ROUTING
2009-09-24 12:00:00.382797 [DEBUG] switch_core_state_machine.c:484 (sofia/external/31354228) State ROUTING
2009-09-24 12:00:00.382797 [DEBUG] mod_sofia.c:130 sofia/external/31354228 SOFIA ROUTING
2009-09-24 12:00:00.382797 [DEBUG] switch_ivr_originate.c:63 (sofia/external/31354228) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2009-09-24 12:00:00.382797 [DEBUG] switch_core_session.c:932 Send signal sofia/external/31354228 [BREAK]
2009-09-24 12:00:00.382797 [DEBUG] switch_core_state_machine.c:484 (sofia/external/31354228) State ROUTING going to sleep
2009-09-24 12:00:00.382797 [DEBUG] switch_core_state_machine.c:398 (sofia/external/31354228) Running State Change CS_CONSUME_MEDIA
2009-09-24 12:00:00.382797 [DEBUG] switch_core_state_machine.c:503 (sofia/external/31354228) State CONSUME_MEDIA
2009-09-24 12:00:00.387422 [DEBUG] switch_ivr_originate.c:1718 Raw Codec Activation Success L16@8000hz 1 channel 20ms
2009-09-24 12:00:00.387422 [DEBUG] switch_ivr_originate.c:1777 Play Ringback Tone [%(2000,4000,440,480)]
2009-09-24 12:00:00.411368 [DEBUG] switch_core_io.c:649 sofia/external/unknown@129.142.224.250 receive message [TRANSCODING_NECESSARY]
2009-09-24 12:00:00.411368 [DEBUG] sofia.c:3302 Channel sofia/external/unknown@129.142.224.250 entering state [ready][200]
2009-09-24 12:00:00.432247 [DEBUG] sofia.c:3302 Channel sofia/external/31354228 entering state [calling][0]
2009-09-24 12:00:01.268196 [DEBUG] sofia.c:3302 Channel sofia/external/31354228 entering state [proceeding][183]
2009-09-24 12:00:01.268196 [DEBUG] sofia.c:3309 Remote SDP:
v=0
o=root 18982 18982 IN IP4 129.142.224.250
s=session
c=IN IP4 129.142.224.250
t=0 0
m=audio 15358 RTP/AVP 8
a=rtpmap:8 PCMA/8000
a=silenceSupp:off - - - -
a=ptime:20

2009-09-24 12:00:01.268196 [DEBUG] sofia_glue.c:3132 Audio Codec Compare [PCMA:8:8000:20]/[PCMA:8:8000:20]
2009-09-24 12:00:01.268196 [DEBUG] sofia_glue.c:2090 Set Codec sofia/external/31354228 PCMA/8000 20 ms 160 samples
2009-09-24 12:00:01.268196 [DEBUG] sofia_glue.c:2324 AUDIO RTP [sofia/external/31354228] 10.227.10.228 port 27678 -> 129.142.224.250 port 15358 codec: 8 ms: 20
2009-09-24 12:00:01.268196 [DEBUG] switch_rtp.c:1139 Starting timer [soft] 1