Hi I've got a problem with FS core dump - http://pastebin.freeswitch.org/17255 When FS shuts down with a core dump it restarts but all calls are disconnected after 30 seconds. Only restart helps for some time. In CDR i see at these calls hangup_cause NORMAL_UNSPECIFIED and billsec 33 or 34 seconds. I cannot find anything interesting in logs... Here it is: b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.103283 [NOTICE] switch_channel.c:907 New Channel sofia/external/501XXXXXX@trunk.dialog.pl [b541f405-1a39-4cbc-80dc-8bdbc92ed070] b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.103283 [DEBUG] sofia.c:5142 Channel sofia/external/501XXXXXX@trunk.dialog.pl entering state [received][100] b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.103283 [DEBUG] switch_core_state_machine.c:330 (sofia/external/501XXXXXX@trunk.dialog.pl) Running State Change CS_NEW b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.103283 [DEBUG] sofia.c:5153 Remote SDP: v=0 o=BroadWorks 51808039 1 IN IP4 10.165.64.36 s=- c=IN IP4 10.165.64.36 t=0 0 m=audio 22558 RTP/AVP 0 8 101 b=AS:82 a=rtpmap:0 PCMU/8000/1 a=rtpmap:8 PCMA/8000/1 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.103283 [DEBUG] switch_core_state_machine.c:348 (sofia/external/501XXXXXX@trunk.dialog.pl) State NEW b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.103283 [DEBUG] sofia_glue.c:4731 Audio Codec Compare [PCMU:0:8000:20:64000]/[G722:9:8000:20:64000] b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.103283 [DEBUG] sofia_glue.c:4731 Audio Codec Compare [PCMU:0:8000:20:64000]/[PCMU:0:8000:20:64000] b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.103283 [DEBUG] sofia_glue.c:2839 Set Codec sofia/external/501XXXXXX@trunk.dialog.pl PCMU/8000 20 ms 160 samples 64000 bits b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.103283 [DEBUG] sofia_glue.c:4845 Set 2833 dtmf send/recv payload to 101 b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.103283 [DEBUG] sofia.c:5343 (sofia/external/501XXXXXX@trunk.dialog.pl) State Change CS_NEW -> CS_INIT b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.103283 [DEBUG] switch_core_session.c:1156 Send signal sofia/external/501XXXXXX@trunk.dialog.pl [BREAK] b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.103283 [DEBUG] switch_core_state_machine.c:330 (sofia/external/501XXXXXX@trunk.dialog.pl) Running State Change CS_INIT b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.103283 [DEBUG] switch_core_state_machine.c:369 (sofia/external/501XXXXXX@trunk.dialog.pl) State INIT b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.103283 [DEBUG] mod_sofia.c:85 sofia/external/501XXXXXX@trunk.dialog.pl SOFIA INIT b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.103283 [DEBUG] mod_sofia.c:125 (sofia/external/501XXXXXX@trunk.dialog.pl) State Change CS_INIT -> CS_ROUTING b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.103283 [DEBUG] switch_core_session.c:1156 Send signal sofia/external/501XXXXXX@trunk.dialog.pl [BREAK] b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.103283 [DEBUG] switch_core_state_machine.c:369 (sofia/external/501XXXXXX@trunk.dialog.pl) State INIT going to sleep b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.103283 [DEBUG] switch_core_state_machine.c:330 (sofia/external/501XXXXXX@trunk.dialog.pl) Running State Change CS_ROUTING b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.103283 [DEBUG] switch_channel.c:1836 (sofia/external/501XXXXXX@trunk.dialog.pl) Callstate Change DOWN -> RINGING b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.103283 [DEBUG] switch_core_state_machine.c:378 (sofia/external/501XXXXXX@trunk.dialog.pl) State ROUTING b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.103283 [DEBUG] mod_sofia.c:148 sofia/external/501XXXXXX@trunk.dialog.pl SOFIA ROUTING b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.103283 [DEBUG] switch_core_state_machine.c:78 sofia/external/501XXXXXX@trunk.dialog.pl Standard ROUTING b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.103283 [INFO] mod_dialplan_xml.c:336 Processing 501XXXXXX <501XXXXXX>->71XXXXXXX in context public b541f405-1a39-4cbc-80dc-8bdbc92ed070 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl parsing [public->unloop] continue=false b541f405-1a39-4cbc-80dc-8bdbc92ed070 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false b541f405-1a39-4cbc-80dc-8bdbc92ed070 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false b541f405-1a39-4cbc-80dc-8bdbc92ed070 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl parsing [public->outside_call] continue=true b541f405-1a39-4cbc-80dc-8bdbc92ed070 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl Absolute Condition [outside_call] b541f405-1a39-4cbc-80dc-8bdbc92ed070 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl Action set(outside_call=true) b541f405-1a39-4cbc-80dc-8bdbc92ed070 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) b541f405-1a39-4cbc-80dc-8bdbc92ed070 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl parsing [public->call_debug] continue=true b541f405-1a39-4cbc-80dc-8bdbc92ed070 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl Regex (FAIL) [call_debug] ${call_debug}(false) =~ /^true$/ break=never b541f405-1a39-4cbc-80dc-8bdbc92ed070 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl parsing [public->public_extensions] continue=false b541f405-1a39-4cbc-80dc-8bdbc92ed070 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl Regex (FAIL) [public_extensions] destination_number(71XXXXXXX) =~ /^(1[0-9][0-9][0-9])$/ break=on-false b541f405-1a39-4cbc-80dc-8bdbc92ed070 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl parsing [public->in_dialog_1] continue=false b541f405-1a39-4cbc-80dc-8bdbc92ed070 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl Date/Time Match (FAIL) [in_dialog_1] break=on-true b541f405-1a39-4cbc-80dc-8bdbc92ed070 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl Regex (PASS) [in_dialog_1] destination_number(71XXXXXXX) =~ /^(717739100|71XXXXXXX|717854012)$/ break=on-false b541f405-1a39-4cbc-80dc-8bdbc92ed070 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl Action set(RECORD_STEREO=true) b541f405-1a39-4cbc-80dc-8bdbc92ed070 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl Action record_session(/srv/nagrania/aktualne/IN_${strftime(%Y%m%d-%H%M%S)}_${destination_number}_${caller_id_number}.wav) b541f405-1a39-4cbc-80dc-8bdbc92ed070 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl Action set(media_bug_answer_req=true) b541f405-1a39-4cbc-80dc-8bdbc92ed070 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl Action set(domain_name=192.168.0.8) b541f405-1a39-4cbc-80dc-8bdbc92ed070 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl Action export(absolute_codec_string=PCMU,PCMA) b541f405-1a39-4cbc-80dc-8bdbc92ed070 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl Action export(codec_string=PCMU,PCMA) b541f405-1a39-4cbc-80dc-8bdbc92ed070 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl Action set(jitterbuffer_msec=180) b541f405-1a39-4cbc-80dc-8bdbc92ed070 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl Action set_audio_level(read 1) b541f405-1a39-4cbc-80dc-8bdbc92ed070 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl Action set(hangup_after_bridge=true) b541f405-1a39-4cbc-80dc-8bdbc92ed070 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl Action set(bind_meta_key=9) b541f405-1a39-4cbc-80dc-8bdbc92ed070 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl Action bind_meta_app(1 b s execute_extension::dx XML features) b541f405-1a39-4cbc-80dc-8bdbc92ed070 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl Action bind_meta_app(2 b s execute_extension::cf XML features) b541f405-1a39-4cbc-80dc-8bdbc92ed070 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl Action bind_meta_app(3 b s execute_extension::att_xfer XML features) b541f405-1a39-4cbc-80dc-8bdbc92ed070 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl Action set(call_timeout=60) b541f405-1a39-4cbc-80dc-8bdbc92ed070 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl Action set(continue_on_fail=NO_ANSWER) b541f405-1a39-4cbc-80dc-8bdbc92ed070 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl Action set(limit_ignore_transfer=true) b541f405-1a39-4cbc-80dc-8bdbc92ed070 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl Action answer() b541f405-1a39-4cbc-80dc-8bdbc92ed070 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl Action sleep(1000) b541f405-1a39-4cbc-80dc-8bdbc92ed070 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl Action set(fifo_music=/srv/nagrania/ivr/ponce-preludio-in-e-major-10s.wav) b541f405-1a39-4cbc-80dc-8bdbc92ed070 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl Action ivr(ivr) b541f405-1a39-4cbc-80dc-8bdbc92ed070 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl Action fifo(fifo_ogolne in) b541f405-1a39-4cbc-80dc-8bdbc92ed070 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl Action hangup() b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.103283 [DEBUG] switch_core_state_machine.c:122 (sofia/external/501XXXXXX@trunk.dialog.pl) State Change CS_ROUTING -> CS_EXECUTE b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.103283 [DEBUG] switch_core_session.c:1156 Send signal sofia/external/501XXXXXX@trunk.dialog.pl [BREAK] b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.103283 [DEBUG] switch_core_state_machine.c:378 (sofia/external/501XXXXXX@trunk.dialog.pl) State ROUTING going to sleep b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.103283 [DEBUG] switch_core_state_machine.c:330 (sofia/external/501XXXXXX@trunk.dialog.pl) Running State Change CS_EXECUTE b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.103283 [DEBUG] switch_core_state_machine.c:385 (sofia/external/501XXXXXX@trunk.dialog.pl) State EXECUTE b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.103283 [DEBUG] mod_sofia.c:241 sofia/external/501XXXXXX@trunk.dialog.pl SOFIA EXECUTE b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.103283 [DEBUG] switch_core_state_machine.c:160 sofia/external/501XXXXXX@trunk.dialog.pl Standard EXECUTE b541f405-1a39-4cbc-80dc-8bdbc92ed070 EXECUTE sofia/external/501XXXXXX@trunk.dialog.pl set(outside_call=true) b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.103283 [DEBUG] mod_dptools.c:1063 sofia/external/501XXXXXX@trunk.dialog.pl SET [outside_call]=[true] b541f405-1a39-4cbc-80dc-8bdbc92ed070 EXECUTE sofia/external/501XXXXXX@trunk.dialog.pl set(RFC2822_DATE=Thu, 01 Sep 2011 08:36:08 +0200) b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.103283 [DEBUG] mod_dptools.c:1063 sofia/external/501XXXXXX@trunk.dialog.pl SET [RFC2822_DATE]=[Thu, 01 Sep 2011 08:36:08 +0200] b541f405-1a39-4cbc-80dc-8bdbc92ed070 EXECUTE sofia/external/501XXXXXX@trunk.dialog.pl set(RECORD_STEREO=true) b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.103283 [DEBUG] mod_dptools.c:1063 sofia/external/501XXXXXX@trunk.dialog.pl SET [RECORD_STEREO]=[true] b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.103283 [DEBUG] switch_core_session.c:1983 Application record_session Requires media! pre_answering channel sofia/external/501XXXXXX@trunk.dialog.pl 2011-09-01 08:36:08.103283 [INFO] switch_core_session.c:1985 Sending early media 2011-09-01 08:36:08.143282 [DEBUG] switch_nat.c:510 mapped public port 29830 protocol UDP to localport 29830 2011-09-01 08:36:08.163284 [DEBUG] switch_nat.c:510 mapped public port 29831 protocol UDP to localport 29831 b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.163284 [DEBUG] sofia_glue.c:3091 AUDIO RTP [sofia/external/501XXXXXX@trunk.dialog.pl] 172.20.0.22 port 29830 -> 10.165.64.36 port 22558 codec: 0 ms: 20 b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.163284 [DEBUG] switch_rtp.c:1637 Starting timer [soft] 160 bytes per 20ms b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.163284 [DEBUG] sofia_glue.c:3353 Set 2833 dtmf send payload to 101 b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.163284 [DEBUG] sofia_glue.c:3358 Set 2833 dtmf receive payload to 101 b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.163284 [DEBUG] mod_sofia.c:2436 Ring SDP: v=0 o=FreeSWITCH 1314829138 1314829139 IN IP4 10.64.64.64 s=FreeSWITCH c=IN IP4 10.64.64.64 t=0 0 m=audio 29830 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.163284 [NOTICE] mod_sofia.c:2439 Pre-Answer sofia/external/501XXXXXX@trunk.dialog.pl! b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.163284 [DEBUG] switch_channel.c:2851 (sofia/external/501XXXXXX@trunk.dialog.pl) Callstate Change RINGING -> EARLY b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.183289 [DEBUG] switch_core_session.c:713 Send signal sofia/external/501XXXXXX@trunk.dialog.pl [BREAK] b541f405-1a39-4cbc-80dc-8bdbc92ed070 EXECUTE sofia/external/501XXXXXX@trunk.dialog.pl record_session(/srv/nagrania/aktualne/IN_20110901-083608_71XXXXXXX_501XXXXXX.wav) b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.183289 [DEBUG] switch_core_session.c:857 Send signal sofia/external/501XXXXXX@trunk.dialog.pl [BREAK] b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.183289 [DEBUG] sofia.c:5135 Channel sofia/external/501XXXXXX@trunk.dialog.pl skipping state [early][183] b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.183289 [DEBUG] switch_core_media_bug.c:360 Attaching BUG to sofia/external/501XXXXXX@trunk.dialog.pl b541f405-1a39-4cbc-80dc-8bdbc92ed070 EXECUTE sofia/external/501XXXXXX@trunk.dialog.pl set(media_bug_answer_req=true) b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.183289 [DEBUG] mod_dptools.c:1063 sofia/external/501XXXXXX@trunk.dialog.pl SET [media_bug_answer_req]=[true] b541f405-1a39-4cbc-80dc-8bdbc92ed070 EXECUTE sofia/external/501XXXXXX@trunk.dialog.pl set(domain_name=192.168.0.8) b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.183289 [DEBUG] mod_dptools.c:1063 sofia/external/501XXXXXX@trunk.dialog.pl SET [domain_name]=[192.168.0.8] b541f405-1a39-4cbc-80dc-8bdbc92ed070 EXECUTE sofia/external/501XXXXXX@trunk.dialog.pl export(absolute_codec_string=PCMU,PCMA) b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.183289 [DEBUG] switch_channel.c:1074 EXPORT (export_vars) [absolute_codec_string]=[PCMU,PCMA] b541f405-1a39-4cbc-80dc-8bdbc92ed070 EXECUTE sofia/external/501XXXXXX@trunk.dialog.pl export(codec_string=PCMU,PCMA) b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.183289 [DEBUG] switch_channel.c:1074 EXPORT (export_vars) [codec_string]=[PCMU,PCMA] b541f405-1a39-4cbc-80dc-8bdbc92ed070 EXECUTE sofia/external/501XXXXXX@trunk.dialog.pl set(jitterbuffer_msec=180) b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.183289 [DEBUG] mod_dptools.c:1063 sofia/external/501XXXXXX@trunk.dialog.pl SET [jitterbuffer_msec]=[180] b541f405-1a39-4cbc-80dc-8bdbc92ed070 EXECUTE sofia/external/501XXXXXX@trunk.dialog.pl set_audio_level(read 1) b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.183289 [DEBUG] switch_core_media_bug.c:360 Attaching BUG to sofia/external/501XXXXXX@trunk.dialog.pl b541f405-1a39-4cbc-80dc-8bdbc92ed070 EXECUTE sofia/external/501XXXXXX@trunk.dialog.pl set(hangup_after_bridge=true) b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.183289 [DEBUG] mod_dptools.c:1063 sofia/external/501XXXXXX@trunk.dialog.pl SET [hangup_after_bridge]=[true] b541f405-1a39-4cbc-80dc-8bdbc92ed070 EXECUTE sofia/external/501XXXXXX@trunk.dialog.pl set(bind_meta_key=9) b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.183289 [DEBUG] mod_dptools.c:1063 sofia/external/501XXXXXX@trunk.dialog.pl SET [bind_meta_key]=[9] b541f405-1a39-4cbc-80dc-8bdbc92ed070 EXECUTE sofia/external/501XXXXXX@trunk.dialog.pl bind_meta_app(1 b s execute_extension::dx XML features) b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.183289 [INFO] switch_ivr_async.c:3069 Bound B-Leg: 91 execute_extension::dx XML features b541f405-1a39-4cbc-80dc-8bdbc92ed070 EXECUTE sofia/external/501XXXXXX@trunk.dialog.pl bind_meta_app(2 b s execute_extension::cf XML features) b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.183289 [INFO] switch_ivr_async.c:3069 Bound B-Leg: 92 execute_extension::cf XML features b541f405-1a39-4cbc-80dc-8bdbc92ed070 EXECUTE sofia/external/501XXXXXX@trunk.dialog.pl bind_meta_app(3 b s execute_extension::att_xfer XML features) b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.183289 [INFO] switch_ivr_async.c:3069 Bound B-Leg: 93 execute_extension::att_xfer XML features b541f405-1a39-4cbc-80dc-8bdbc92ed070 EXECUTE sofia/external/501XXXXXX@trunk.dialog.pl set(call_timeout=60) b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.183289 [DEBUG] mod_dptools.c:1063 sofia/external/501XXXXXX@trunk.dialog.pl SET [call_timeout]=[60] b541f405-1a39-4cbc-80dc-8bdbc92ed070 EXECUTE sofia/external/501XXXXXX@trunk.dialog.pl set(continue_on_fail=NO_ANSWER) b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.183289 [DEBUG] mod_dptools.c:1063 sofia/external/501XXXXXX@trunk.dialog.pl SET [continue_on_fail]=[NO_ANSWER] b541f405-1a39-4cbc-80dc-8bdbc92ed070 EXECUTE sofia/external/501XXXXXX@trunk.dialog.pl set(limit_ignore_transfer=true) b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.183289 [DEBUG] mod_dptools.c:1063 sofia/external/501XXXXXX@trunk.dialog.pl SET [limit_ignore_transfer]=[true] b541f405-1a39-4cbc-80dc-8bdbc92ed070 EXECUTE sofia/external/501XXXXXX@trunk.dialog.pl answer() b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.183289 [DEBUG] mod_sofia.c:738 Local SDP sofia/external/501XXXXXX@trunk.dialog.pl: v=0 o=FreeSWITCH 1314829138 1314829140 IN IP4 10.64.64.64 s=FreeSWITCH c=IN IP4 10.64.64.64 t=0 0 m=audio 29830 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.183289 [DEBUG] switch_core_session.c:713 Send signal sofia/external/501XXXXXX@trunk.dialog.pl [BREAK] b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.183289 [DEBUG] switch_channel.c:3043 (sofia/external/501XXXXXX@trunk.dialog.pl) Callstate Change EARLY -> ACTIVE b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.183289 [DEBUG] switch_core_session.c:857 Send signal sofia/external/501XXXXXX@trunk.dialog.pl [BREAK] b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.183289 [NOTICE] mod_dptools.c:930 Channel [sofia/external/501XXXXXX@trunk.dialog.pl] has been answered b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:08.183289 [DEBUG] sofia.c:5142 Channel sofia/external/501XXXXXX@trunk.dialog.pl entering state [completed][200] b541f405-1a39-4cbc-80dc-8bdbc92ed070 EXECUTE sofia/external/501XXXXXX@trunk.dialog.pl sleep(1000) b541f405-1a39-4cbc-80dc-8bdbc92ed070 EXECUTE sofia/external/501XXXXXX@trunk.dialog.pl set(fifo_music=/srv/nagrania/ivr/ponce-preludio-in-e-major-10s.wav) b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:09.203286 [DEBUG] mod_dptools.c:1063 sofia/external/501XXXXXX@trunk.dialog.pl SET [fifo_music]=[/srv/nagrania/ivr/ponce-preludio-in-e-major-10s.wav] b541f405-1a39-4cbc-80dc-8bdbc92ed070 EXECUTE sofia/external/501XXXXXX@trunk.dialog.pl ivr(ivr) 2011-09-01 08:36:09.203286 [DEBUG] switch_ivr_menu.c:660 switch_ivr_menu_stack_xml_add binding 'menu-exit' 2011-09-01 08:36:09.203286 [DEBUG] switch_ivr_menu.c:660 switch_ivr_menu_stack_xml_add binding 'menu-sub' 2011-09-01 08:36:09.203286 [DEBUG] switch_ivr_menu.c:660 switch_ivr_menu_stack_xml_add binding 'menu-exec-app' 2011-09-01 08:36:09.203286 [DEBUG] switch_ivr_menu.c:660 switch_ivr_menu_stack_xml_add binding 'menu-play-sound' 2011-09-01 08:36:09.203286 [DEBUG] switch_ivr_menu.c:660 switch_ivr_menu_stack_xml_add binding 'menu-back' 2011-09-01 08:36:09.203286 [DEBUG] switch_ivr_menu.c:660 switch_ivr_menu_stack_xml_add binding 'menu-top' 2011-09-01 08:36:09.203286 [DEBUG] switch_ivr_menu.c:791 building menu 'ivr' 2011-09-01 08:36:09.203286 [DEBUG] switch_ivr_menu.c:852 binding menu action 'menu-exec-app' to '1' 2011-09-01 08:36:09.203286 [DEBUG] switch_ivr_menu.c:852 binding menu action 'menu-exec-app' to '2' 2011-09-01 08:36:09.203286 [DEBUG] switch_ivr_menu.c:852 binding menu action 'menu-top' to '9' b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:09.203286 [DEBUG] switch_ivr_menu.c:428 Executing IVR menu ivr 2011-09-01 08:36:09.203286 [DEBUG] switch_core_file.c:180 File /srv/nagrania/ivr/powitanie_pelne.wav sample rate 22050 doesn't match requested rate 8000 b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:09.203286 [DEBUG] switch_ivr_play_say.c:1302 Codec Activated L16@8000hz 1 channels 20ms b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:09.203286 [DEBUG] switch_ivr_play_say.c:1351 Setup timer success 320 bytes per 20 ms! b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:26.823286 [DEBUG] switch_ivr_play_say.c:1672 done playing file b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:26.823286 [DEBUG] switch_ivr_menu.c:343 waiting for 1/1 digits t/o 2000 2011-09-01 08:36:30.443283 [DEBUG] switch_nat.c:306 got UPnP keep alive packet: NOTIFY * HTTP/1.1 HOST: 239.255.255.250:1900 CACHE-CONTROL: max-age=180 Location: http://192.168.0.6:5431/dyndev/uuid:001c1091-9dfb-001c-1091-9dfb00005800 NT: urn:schemas-upnp-org:service:WANPPPConnection:1 NTS: ssdp:alive SERVER:LINUX/2.4 UPnP/1.0 BRCM400/1.0 USN: uuid:001c1091-9dfb-001c-1091-9dfb02005800::urn:schemas-upnp-org:service:WANPPPConnection:1 b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:31.843284 [DEBUG] switch_ivr_menu.c:390 digits '' 2011-09-01 08:36:31.843284 [DEBUG] switch_core_file.c:180 File /srv/nagrania/ivr/powitanie_skrocone.wav sample rate 22050 doesn't match requested rate 8000 b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:31.843284 [DEBUG] switch_ivr_play_say.c:1302 Codec Activated L16@8000hz 1 channels 20ms b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:31.843284 [DEBUG] switch_ivr_play_say.c:1351 Setup timer success 320 bytes per 20 ms! 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.283283 [NOTICE] switch_channel.c:907 New Channel sofia/external/501XXXXXX@trunk.dialog.pl [28f96f4c-4fd0-4d19-bd69-6b08e6887db2] 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.283283 [DEBUG] sofia.c:5142 Channel sofia/external/501XXXXXX@trunk.dialog.pl entering state [received][100] 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.283283 [DEBUG] switch_core_state_machine.c:330 (sofia/external/501XXXXXX@trunk.dialog.pl) Running State Change CS_NEW 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.283283 [DEBUG] sofia.c:5153 Remote SDP: v=0 o=BroadWorks 51808287 1 IN IP4 10.165.64.36 s=- c=IN IP4 10.165.64.36 t=0 0 m=audio 22914 RTP/AVP 0 8 101 b=AS:82 a=rtpmap:0 PCMU/8000/1 a=rtpmap:8 PCMA/8000/1 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.283283 [DEBUG] switch_core_state_machine.c:348 (sofia/external/501XXXXXX@trunk.dialog.pl) State NEW 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.283283 [DEBUG] sofia_glue.c:4731 Audio Codec Compare [PCMU:0:8000:20:64000]/[G722:9:8000:20:64000] 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.283283 [DEBUG] sofia_glue.c:4731 Audio Codec Compare [PCMU:0:8000:20:64000]/[PCMU:0:8000:20:64000] 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.283283 [DEBUG] sofia_glue.c:2839 Set Codec sofia/external/501XXXXXX@trunk.dialog.pl PCMU/8000 20 ms 160 samples 64000 bits 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.283283 [DEBUG] sofia_glue.c:4845 Set 2833 dtmf send/recv payload to 101 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.283283 [DEBUG] sofia.c:5343 (sofia/external/501XXXXXX@trunk.dialog.pl) State Change CS_NEW -> CS_INIT 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.283283 [DEBUG] switch_core_session.c:1156 Send signal sofia/external/501XXXXXX@trunk.dialog.pl [BREAK] 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.283283 [DEBUG] switch_core_state_machine.c:330 (sofia/external/501XXXXXX@trunk.dialog.pl) Running State Change CS_INIT 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.283283 [DEBUG] switch_core_state_machine.c:369 (sofia/external/501XXXXXX@trunk.dialog.pl) State INIT 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.283283 [DEBUG] mod_sofia.c:85 sofia/external/501XXXXXX@trunk.dialog.pl SOFIA INIT 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.283283 [DEBUG] mod_sofia.c:125 (sofia/external/501XXXXXX@trunk.dialog.pl) State Change CS_INIT -> CS_ROUTING 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.283283 [DEBUG] switch_core_session.c:1156 Send signal sofia/external/501XXXXXX@trunk.dialog.pl [BREAK] 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.283283 [DEBUG] switch_core_state_machine.c:369 (sofia/external/501XXXXXX@trunk.dialog.pl) State INIT going to sleep 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.283283 [DEBUG] switch_core_state_machine.c:330 (sofia/external/501XXXXXX@trunk.dialog.pl) Running State Change CS_ROUTING 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.283283 [DEBUG] switch_channel.c:1836 (sofia/external/501XXXXXX@trunk.dialog.pl) Callstate Change DOWN -> RINGING 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.283283 [DEBUG] switch_core_state_machine.c:378 (sofia/external/501XXXXXX@trunk.dialog.pl) State ROUTING 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.283283 [DEBUG] mod_sofia.c:148 sofia/external/501XXXXXX@trunk.dialog.pl SOFIA ROUTING 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.283283 [DEBUG] switch_core_state_machine.c:78 sofia/external/501XXXXXX@trunk.dialog.pl Standard ROUTING 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.283283 [INFO] mod_dialplan_xml.c:336 Processing 501XXXXXX <501XXXXXX>->71XXXXXXX in context public 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl parsing [public->unloop] continue=false 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl parsing [public->outside_call] continue=true 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl Absolute Condition [outside_call] 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl Action set(outside_call=true) 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl parsing [public->call_debug] continue=true 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl Regex (FAIL) [call_debug] ${call_debug}(false) =~ /^true$/ break=never 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl parsing [public->public_extensions] continue=false 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl Regex (FAIL) [public_extensions] destination_number(71XXXXXXX) =~ /^(1[0-9][0-9][0-9])$/ break=on-false 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl parsing [public->in_dialog_1] continue=false 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl Date/Time Match (FAIL) [in_dialog_1] break=on-true 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl Regex (PASS) [in_dialog_1] destination_number(71XXXXXXX) =~ /^(717739100|71XXXXXXX|717854012)$/ break=on-false 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl Action set(RECORD_STEREO=true) 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl Action record_session(/srv/nagrania/aktualne/IN_${strftime(%Y%m%d-%H%M%S)}_${destination_number}_${caller_id_number}.wav) 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl Action set(media_bug_answer_req=true) 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl Action set(domain_name=192.168.0.8) 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl Action export(absolute_codec_string=PCMU,PCMA) 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl Action export(codec_string=PCMU,PCMA) 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl Action set(jitterbuffer_msec=180) 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl Action set_audio_level(read 1) 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl Action set(hangup_after_bridge=true) 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl Action set(bind_meta_key=9) 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl Action bind_meta_app(1 b s execute_extension::dx XML features) 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl Action bind_meta_app(2 b s execute_extension::cf XML features) 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl Action bind_meta_app(3 b s execute_extension::att_xfer XML features) 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl Action set(call_timeout=60) 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl Action set(continue_on_fail=NO_ANSWER) 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl Action set(limit_ignore_transfer=true) 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl Action answer() 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl Action sleep(1000) 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl Action set(fifo_music=/srv/nagrania/ivr/ponce-preludio-in-e-major-10s.wav) 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl Action ivr(ivr) 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl Action fifo(fifo_ogolne in) 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 Dialplan: sofia/external/501XXXXXX@trunk.dialog.pl Action hangup() 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.283283 [DEBUG] switch_core_state_machine.c:122 (sofia/external/501XXXXXX@trunk.dialog.pl) State Change CS_ROUTING -> CS_EXECUTE 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.283283 [DEBUG] switch_core_session.c:1156 Send signal sofia/external/501XXXXXX@trunk.dialog.pl [BREAK] 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.283283 [DEBUG] switch_core_state_machine.c:378 (sofia/external/501XXXXXX@trunk.dialog.pl) State ROUTING going to sleep 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.283283 [DEBUG] switch_core_state_machine.c:330 (sofia/external/501XXXXXX@trunk.dialog.pl) Running State Change CS_EXECUTE 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.283283 [DEBUG] switch_core_state_machine.c:385 (sofia/external/501XXXXXX@trunk.dialog.pl) State EXECUTE 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.283283 [DEBUG] mod_sofia.c:241 sofia/external/501XXXXXX@trunk.dialog.pl SOFIA EXECUTE 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.283283 [DEBUG] switch_core_state_machine.c:160 sofia/external/501XXXXXX@trunk.dialog.pl Standard EXECUTE 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 EXECUTE sofia/external/501XXXXXX@trunk.dialog.pl set(outside_call=true) 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.283283 [DEBUG] mod_dptools.c:1063 sofia/external/501XXXXXX@trunk.dialog.pl SET [outside_call]=[true] 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 EXECUTE sofia/external/501XXXXXX@trunk.dialog.pl set(RFC2822_DATE=Thu, 01 Sep 2011 08:36:35 +0200) 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.283283 [DEBUG] mod_dptools.c:1063 sofia/external/501XXXXXX@trunk.dialog.pl SET [RFC2822_DATE]=[Thu, 01 Sep 2011 08:36:35 +0200] 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 EXECUTE sofia/external/501XXXXXX@trunk.dialog.pl set(RECORD_STEREO=true) 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.283283 [DEBUG] mod_dptools.c:1063 sofia/external/501XXXXXX@trunk.dialog.pl SET [RECORD_STEREO]=[true] 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.283283 [DEBUG] switch_core_session.c:1983 Application record_session Requires media! pre_answering channel sofia/external/501XXXXXX@trunk.dialog.pl 2011-09-01 08:36:35.283283 [INFO] switch_core_session.c:1985 Sending early media 2011-09-01 08:36:35.323283 [DEBUG] switch_nat.c:510 mapped public port 30160 protocol UDP to localport 30160 2011-09-01 08:36:35.363285 [DEBUG] switch_nat.c:510 mapped public port 30161 protocol UDP to localport 30161 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.363285 [DEBUG] sofia_glue.c:3091 AUDIO RTP [sofia/external/501XXXXXX@trunk.dialog.pl] 172.20.0.22 port 30160 -> 10.165.64.36 port 22914 codec: 0 ms: 20 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.363285 [DEBUG] switch_rtp.c:1637 Starting timer [soft] 160 bytes per 20ms 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.363285 [DEBUG] sofia_glue.c:3353 Set 2833 dtmf send payload to 101 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.363285 [DEBUG] sofia_glue.c:3358 Set 2833 dtmf receive payload to 101 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.363285 [DEBUG] mod_sofia.c:2436 Ring SDP: v=0 o=FreeSWITCH 1314828835 1314828836 IN IP4 10.64.64.64 s=FreeSWITCH c=IN IP4 10.64.64.64 t=0 0 m=audio 30160 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.363285 [NOTICE] mod_sofia.c:2439 Pre-Answer sofia/external/501XXXXXX@trunk.dialog.pl! 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.363285 [DEBUG] switch_channel.c:2851 (sofia/external/501XXXXXX@trunk.dialog.pl) Callstate Change RINGING -> EARLY 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.363285 [DEBUG] switch_core_session.c:713 Send signal sofia/external/501XXXXXX@trunk.dialog.pl [BREAK] 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 EXECUTE sofia/external/501XXXXXX@trunk.dialog.pl record_session(/srv/nagrania/aktualne/IN_20110901-083635_71XXXXXXX_501XXXXXX.wav) 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.363285 [DEBUG] switch_core_session.c:857 Send signal sofia/external/501XXXXXX@trunk.dialog.pl [BREAK] 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.363285 [DEBUG] sofia.c:5135 Channel sofia/external/501XXXXXX@trunk.dialog.pl skipping state [early][183] 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.363285 [DEBUG] switch_core_media_bug.c:360 Attaching BUG to sofia/external/501XXXXXX@trunk.dialog.pl 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 EXECUTE sofia/external/501XXXXXX@trunk.dialog.pl set(media_bug_answer_req=true) 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.363285 [DEBUG] mod_dptools.c:1063 sofia/external/501XXXXXX@trunk.dialog.pl SET [media_bug_answer_req]=[true] 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 EXECUTE sofia/external/501XXXXXX@trunk.dialog.pl set(domain_name=192.168.0.8) 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.363285 [DEBUG] mod_dptools.c:1063 sofia/external/501XXXXXX@trunk.dialog.pl SET [domain_name]=[192.168.0.8] 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 EXECUTE sofia/external/501XXXXXX@trunk.dialog.pl export(absolute_codec_string=PCMU,PCMA) 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.363285 [DEBUG] switch_channel.c:1074 EXPORT (export_vars) [absolute_codec_string]=[PCMU,PCMA] 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 EXECUTE sofia/external/501XXXXXX@trunk.dialog.pl export(codec_string=PCMU,PCMA) 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.363285 [DEBUG] switch_channel.c:1074 EXPORT (export_vars) [codec_string]=[PCMU,PCMA] 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 EXECUTE sofia/external/501XXXXXX@trunk.dialog.pl set(jitterbuffer_msec=180) 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.363285 [DEBUG] mod_dptools.c:1063 sofia/external/501XXXXXX@trunk.dialog.pl SET [jitterbuffer_msec]=[180] 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 EXECUTE sofia/external/501XXXXXX@trunk.dialog.pl set_audio_level(read 1) 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.363285 [DEBUG] switch_core_media_bug.c:360 Attaching BUG to sofia/external/501XXXXXX@trunk.dialog.pl 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 EXECUTE sofia/external/501XXXXXX@trunk.dialog.pl set(hangup_after_bridge=true) 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.363285 [DEBUG] mod_dptools.c:1063 sofia/external/501XXXXXX@trunk.dialog.pl SET [hangup_after_bridge]=[true] 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 EXECUTE sofia/external/501XXXXXX@trunk.dialog.pl set(bind_meta_key=9) 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.363285 [DEBUG] mod_dptools.c:1063 sofia/external/501XXXXXX@trunk.dialog.pl SET [bind_meta_key]=[9] 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 EXECUTE sofia/external/501XXXXXX@trunk.dialog.pl bind_meta_app(1 b s execute_extension::dx XML features) 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.363285 [INFO] switch_ivr_async.c:3069 Bound B-Leg: 91 execute_extension::dx XML features 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 EXECUTE sofia/external/501XXXXXX@trunk.dialog.pl bind_meta_app(2 b s execute_extension::cf XML features) 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.363285 [INFO] switch_ivr_async.c:3069 Bound B-Leg: 92 execute_extension::cf XML features 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 EXECUTE sofia/external/501XXXXXX@trunk.dialog.pl bind_meta_app(3 b s execute_extension::att_xfer XML features) 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.363285 [INFO] switch_ivr_async.c:3069 Bound B-Leg: 93 execute_extension::att_xfer XML features 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 EXECUTE sofia/external/501XXXXXX@trunk.dialog.pl set(call_timeout=60) 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.363285 [DEBUG] mod_dptools.c:1063 sofia/external/501XXXXXX@trunk.dialog.pl SET [call_timeout]=[60] 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 EXECUTE sofia/external/501XXXXXX@trunk.dialog.pl set(continue_on_fail=NO_ANSWER) 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.363285 [DEBUG] mod_dptools.c:1063 sofia/external/501XXXXXX@trunk.dialog.pl SET [continue_on_fail]=[NO_ANSWER] 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 EXECUTE sofia/external/501XXXXXX@trunk.dialog.pl set(limit_ignore_transfer=true) 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.363285 [DEBUG] mod_dptools.c:1063 sofia/external/501XXXXXX@trunk.dialog.pl SET [limit_ignore_transfer]=[true] 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 EXECUTE sofia/external/501XXXXXX@trunk.dialog.pl answer() 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.363285 [DEBUG] mod_sofia.c:738 Local SDP sofia/external/501XXXXXX@trunk.dialog.pl: v=0 o=FreeSWITCH 1314828835 1314828837 IN IP4 10.64.64.64 s=FreeSWITCH c=IN IP4 10.64.64.64 t=0 0 m=audio 30160 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.363285 [DEBUG] switch_core_session.c:713 Send signal sofia/external/501XXXXXX@trunk.dialog.pl [BREAK] 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.363285 [DEBUG] switch_channel.c:3043 (sofia/external/501XXXXXX@trunk.dialog.pl) Callstate Change EARLY -> ACTIVE 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.363285 [DEBUG] switch_core_session.c:857 Send signal sofia/external/501XXXXXX@trunk.dialog.pl [BREAK] 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.363285 [NOTICE] mod_dptools.c:930 Channel [sofia/external/501XXXXXX@trunk.dialog.pl] has been answered 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:35.363285 [DEBUG] sofia.c:5142 Channel sofia/external/501XXXXXX@trunk.dialog.pl entering state [completed][200] 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 EXECUTE sofia/external/501XXXXXX@trunk.dialog.pl sleep(1000) 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 EXECUTE sofia/external/501XXXXXX@trunk.dialog.pl set(fifo_music=/srv/nagrania/ivr/ponce-preludio-in-e-major-10s.wav) 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:36.363287 [DEBUG] mod_dptools.c:1063 sofia/external/501XXXXXX@trunk.dialog.pl SET [fifo_music]=[/srv/nagrania/ivr/ponce-preludio-in-e-major-10s.wav] 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 EXECUTE sofia/external/501XXXXXX@trunk.dialog.pl ivr(ivr) 2011-09-01 08:36:36.363287 [DEBUG] switch_ivr_menu.c:660 switch_ivr_menu_stack_xml_add binding 'menu-exit' 2011-09-01 08:36:36.363287 [DEBUG] switch_ivr_menu.c:660 switch_ivr_menu_stack_xml_add binding 'menu-sub' 2011-09-01 08:36:36.363287 [DEBUG] switch_ivr_menu.c:660 switch_ivr_menu_stack_xml_add binding 'menu-exec-app' 2011-09-01 08:36:36.363287 [DEBUG] switch_ivr_menu.c:660 switch_ivr_menu_stack_xml_add binding 'menu-play-sound' 2011-09-01 08:36:36.363287 [DEBUG] switch_ivr_menu.c:660 switch_ivr_menu_stack_xml_add binding 'menu-back' 2011-09-01 08:36:36.363287 [DEBUG] switch_ivr_menu.c:660 switch_ivr_menu_stack_xml_add binding 'menu-top' 2011-09-01 08:36:36.363287 [DEBUG] switch_ivr_menu.c:791 building menu 'ivr' 2011-09-01 08:36:36.363287 [DEBUG] switch_ivr_menu.c:852 binding menu action 'menu-exec-app' to '1' 2011-09-01 08:36:36.363287 [DEBUG] switch_ivr_menu.c:852 binding menu action 'menu-exec-app' to '2' 2011-09-01 08:36:36.363287 [DEBUG] switch_ivr_menu.c:852 binding menu action 'menu-top' to '9' 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:36.363287 [DEBUG] switch_ivr_menu.c:428 Executing IVR menu ivr 2011-09-01 08:36:36.363287 [DEBUG] switch_core_file.c:180 File /srv/nagrania/ivr/powitanie_pelne.wav sample rate 22050 doesn't match requested rate 8000 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:36.363287 [DEBUG] switch_ivr_play_say.c:1302 Codec Activated L16@8000hz 1 channels 20ms 28f96f4c-4fd0-4d19-bd69-6b08e6887db2 2011-09-01 08:36:36.363287 [DEBUG] switch_ivr_play_say.c:1351 Setup timer success 320 bytes per 20 ms! b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:40.183284 [DEBUG] switch_core_session.c:857 Send signal sofia/external/501XXXXXX@trunk.dialog.pl [BREAK] b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:40.183284 [DEBUG] switch_core_session.c:857 Send signal sofia/external/501XXXXXX@trunk.dialog.pl [BREAK] b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:40.203284 [DEBUG] sofia.c:5142 Channel sofia/external/501XXXXXX@trunk.dialog.pl entering state [terminating][0] b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:40.203284 [DEBUG] switch_channel.c:2775 (sofia/external/501XXXXXX@trunk.dialog.pl) Callstate Change ACTIVE -> HANGUP b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:40.203284 [NOTICE] sofia.c:5867 Hangup sofia/external/501XXXXXX@trunk.dialog.pl [CS_EXECUTE] [NORMAL_UNSPECIFIED] b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:40.203284 [DEBUG] switch_channel.c:2791 Send signal sofia/external/501XXXXXX@trunk.dialog.pl [KILL] b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:40.203284 [DEBUG] switch_core_session.c:1156 Send signal sofia/external/501XXXXXX@trunk.dialog.pl [BREAK] b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:40.203284 [DEBUG] switch_ivr_play_say.c:1672 done playing file b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:40.203284 [DEBUG] switch_ivr_menu.c:343 waiting for 1/1 digits t/o 2000 b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:40.203284 [DEBUG] switch_ivr_menu.c:390 digits '' b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:40.203284 [DEBUG] switch_ivr_menu.c:580 IVR menu 'ivr' no input detected b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:41.203285 [DEBUG] switch_ivr_menu.c:594 exit-sound '/srv/nagrania/ivr/laczenie_z_operatorem.wav' b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:41.203285 [DEBUG] switch_core_session.c:2133 sofia/external/501XXXXXX@trunk.dialog.pl skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:41.203285 [DEBUG] switch_core_state_machine.c:385 (sofia/external/501XXXXXX@trunk.dialog.pl) State EXECUTE going to sleep b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:41.203285 [DEBUG] switch_core_state_machine.c:330 (sofia/external/501XXXXXX@trunk.dialog.pl) Running State Change CS_HANGUP b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:41.203285 [DEBUG] switch_core_media_bug.c:480 Removing BUG from sofia/external/501XXXXXX@trunk.dialog.pl b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:41.203285 [DEBUG] switch_ivr_async.c:937 Stop recording file /srv/nagrania/aktualne/IN_20110901-083608_71XXXXXXX_501XXXXXX.wav b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:41.203285 [DEBUG] switch_core_media_bug.c:480 Removing BUG from sofia/external/501XXXXXX@trunk.dialog.pl b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:41.203285 [DEBUG] switch_core_state_machine.c:580 (sofia/external/501XXXXXX@trunk.dialog.pl) State HANGUP b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:41.203285 [DEBUG] mod_sofia.c:458 Channel sofia/external/501XXXXXX@trunk.dialog.pl hanging up, cause: NORMAL_UNSPECIFIED b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:41.203285 [DEBUG] switch_core_state_machine.c:46 sofia/external/501XXXXXX@trunk.dialog.pl Standard HANGUP, cause: NORMAL_UNSPECIFIED b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:41.203285 [DEBUG] switch_core_state_machine.c:580 (sofia/external/501XXXXXX@trunk.dialog.pl) State HANGUP going to sleep b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:41.203285 [DEBUG] switch_core_state_machine.c:361 (sofia/external/501XXXXXX@trunk.dialog.pl) State Change CS_HANGUP -> CS_REPORTING b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:41.203285 [DEBUG] switch_core_session.c:1156 Send signal sofia/external/501XXXXXX@trunk.dialog.pl [BREAK] b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:41.203285 [DEBUG] switch_core_state_machine.c:330 (sofia/external/501XXXXXX@trunk.dialog.pl) Running State Change CS_REPORTING b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:41.203285 [DEBUG] switch_core_state_machine.c:640 (sofia/external/501XXXXXX@trunk.dialog.pl) State REPORTING b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:41.263295 [DEBUG] switch_core_state_machine.c:53 sofia/external/501XXXXXX@trunk.dialog.pl Standard REPORTING, cause: NORMAL_UNSPECIFIED b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:41.263295 [DEBUG] switch_core_state_machine.c:640 (sofia/external/501XXXXXX@trunk.dialog.pl) State REPORTING going to sleep b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:41.263295 [DEBUG] switch_core_state_machine.c:355 (sofia/external/501XXXXXX@trunk.dialog.pl) State Change CS_REPORTING -> CS_DESTROY b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:41.263295 [DEBUG] switch_core_session.c:1156 Send signal sofia/external/501XXXXXX@trunk.dialog.pl [BREAK] b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:41.263295 [DEBUG] switch_core_session.c:1328 Session 2 (sofia/external/501XXXXXX@trunk.dialog.pl) Locked, Waiting on external entities b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:41.263295 [NOTICE] switch_core_session.c:1346 Session 2 (sofia/external/501XXXXXX@trunk.dialog.pl) Ended b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:41.263295 [NOTICE] switch_core_session.c:1348 Close Channel sofia/external/501XXXXXX@trunk.dialog.pl [CS_DESTROY] b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:41.263295 [DEBUG] switch_core_state_machine.c:469 (sofia/external/501XXXXXX@trunk.dialog.pl) Callstate Change HANGUP -> DOWN b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:41.263295 [DEBUG] switch_core_state_machine.c:472 (sofia/external/501XXXXXX@trunk.dialog.pl) Running State Change CS_DESTROY b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:41.263295 [DEBUG] switch_core_state_machine.c:482 (sofia/external/501XXXXXX@trunk.dialog.pl) State DESTROY b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:41.263295 [DEBUG] mod_sofia.c:363 sofia/external/501XXXXXX@trunk.dialog.pl SOFIA DESTROY b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:41.343286 [DEBUG] switch_core_state_machine.c:60 sofia/external/501XXXXXX@trunk.dialog.pl Standard DESTROY b541f405-1a39-4cbc-80dc-8bdbc92ed070 2011-09-01 08:36:41.343286 [DEBUG] switch_core_state_machine.c:482 (sofia/external/501XXXXXX@trunk.dialog.pl) State DESTROY going to sleep Any ideas ? -- Greetings - Tomasz Hyziak