<html xmlns:v="urn:schemas-microsoft-com:vml" xmlns:o="urn:schemas-microsoft-com:office:office" xmlns:w="urn:schemas-microsoft-com:office:word" xmlns:m="http://schemas.microsoft.com/office/2004/12/omml" xmlns="http://www.w3.org/TR/REC-html40"><head><meta http-equiv=Content-Type content="text/html; charset=us-ascii"><meta name=Generator content="Microsoft Word 14 (filtered medium)"><style><!--
/* Font Definitions */
@font-face
{font-family:Wingdings;
panose-1:5 0 0 0 0 0 0 0 0 0;}
@font-face
{font-family:"Cambria Math";
panose-1:2 4 5 3 5 4 6 3 2 4;}
@font-face
{font-family:Calibri;
panose-1:2 15 5 2 2 2 4 3 2 4;}
@font-face
{font-family:Tahoma;
panose-1:2 11 6 4 3 5 4 4 2 4;}
/* Style Definitions */
p.MsoNormal, li.MsoNormal, div.MsoNormal
{margin:0in;
margin-bottom:.0001pt;
font-size:11.0pt;
font-family:"Calibri","sans-serif";}
a:link, span.MsoHyperlink
{mso-style-priority:99;
color:blue;
text-decoration:underline;}
a:visited, span.MsoHyperlinkFollowed
{mso-style-priority:99;
color:purple;
text-decoration:underline;}
p.MsoPlainText, li.MsoPlainText, div.MsoPlainText
{mso-style-priority:99;
mso-style-link:"Plain Text Char";
margin:0in;
margin-bottom:.0001pt;
font-size:11.0pt;
font-family:"Calibri","sans-serif";}
p.MsoListParagraph, li.MsoListParagraph, div.MsoListParagraph
{mso-style-priority:34;
margin-top:0in;
margin-right:0in;
margin-bottom:0in;
margin-left:.5in;
margin-bottom:.0001pt;
font-size:11.0pt;
font-family:"Calibri","sans-serif";}
span.EmailStyle17
{mso-style-type:personal;
font-family:"Calibri","sans-serif";
color:windowtext;}
span.EmailStyle18
{mso-style-type:personal-reply;
font-family:"Calibri","sans-serif";
color:#1F497D;}
span.PlainTextChar
{mso-style-name:"Plain Text Char";
mso-style-priority:99;
mso-style-link:"Plain Text";
font-family:"Calibri","sans-serif";}
.MsoChpDefault
{mso-style-type:export-only;
font-size:10.0pt;}
@page WordSection1
{size:8.5in 11.0in;
margin:1.0in 1.0in 1.0in 1.0in;}
div.WordSection1
{page:WordSection1;}
/* List Definitions */
@list l0
{mso-list-id:897739214;
mso-list-type:hybrid;
mso-list-template-ids:1782763086 67698689 67698691 67698693 67698689 67698691 67698693 67698689 67698691 67698693;}
@list l0:level1
{mso-level-number-format:bullet;
mso-level-text:\F0B7;
mso-level-tab-stop:none;
mso-level-number-position:left;
text-indent:-.25in;
font-family:Symbol;}
@list l0:level2
{mso-level-number-format:bullet;
mso-level-text:o;
mso-level-tab-stop:none;
mso-level-number-position:left;
text-indent:-.25in;
font-family:"Courier New";}
@list l0:level3
{mso-level-number-format:bullet;
mso-level-text:\F0A7;
mso-level-tab-stop:none;
mso-level-number-position:left;
text-indent:-.25in;
font-family:Wingdings;}
@list l0:level4
{mso-level-number-format:bullet;
mso-level-text:\F0B7;
mso-level-tab-stop:none;
mso-level-number-position:left;
text-indent:-.25in;
font-family:Symbol;}
@list l0:level5
{mso-level-number-format:bullet;
mso-level-text:o;
mso-level-tab-stop:none;
mso-level-number-position:left;
text-indent:-.25in;
font-family:"Courier New";}
@list l0:level6
{mso-level-number-format:bullet;
mso-level-text:\F0A7;
mso-level-tab-stop:none;
mso-level-number-position:left;
text-indent:-.25in;
font-family:Wingdings;}
@list l0:level7
{mso-level-number-format:bullet;
mso-level-text:\F0B7;
mso-level-tab-stop:none;
mso-level-number-position:left;
text-indent:-.25in;
font-family:Symbol;}
@list l0:level8
{mso-level-number-format:bullet;
mso-level-text:o;
mso-level-tab-stop:none;
mso-level-number-position:left;
text-indent:-.25in;
font-family:"Courier New";}
@list l0:level9
{mso-level-number-format:bullet;
mso-level-text:\F0A7;
mso-level-tab-stop:none;
mso-level-number-position:left;
text-indent:-.25in;
font-family:Wingdings;}
@list l1
{mso-list-id:1353145723;
mso-list-type:hybrid;
mso-list-template-ids:668221782 67698689 67698691 67698693 67698689 67698691 67698693 67698689 67698691 67698693;}
@list l1:level1
{mso-level-number-format:bullet;
mso-level-text:\F0B7;
mso-level-tab-stop:none;
mso-level-number-position:left;
text-indent:-.25in;
font-family:Symbol;}
@list l1:level2
{mso-level-number-format:bullet;
mso-level-text:o;
mso-level-tab-stop:none;
mso-level-number-position:left;
text-indent:-.25in;
font-family:"Courier New";}
@list l1:level3
{mso-level-number-format:bullet;
mso-level-text:\F0A7;
mso-level-tab-stop:none;
mso-level-number-position:left;
text-indent:-.25in;
font-family:Wingdings;}
@list l1:level4
{mso-level-number-format:bullet;
mso-level-text:\F0B7;
mso-level-tab-stop:none;
mso-level-number-position:left;
text-indent:-.25in;
font-family:Symbol;}
@list l1:level5
{mso-level-number-format:bullet;
mso-level-text:o;
mso-level-tab-stop:none;
mso-level-number-position:left;
text-indent:-.25in;
font-family:"Courier New";}
@list l1:level6
{mso-level-number-format:bullet;
mso-level-text:\F0A7;
mso-level-tab-stop:none;
mso-level-number-position:left;
text-indent:-.25in;
font-family:Wingdings;}
@list l1:level7
{mso-level-number-format:bullet;
mso-level-text:\F0B7;
mso-level-tab-stop:none;
mso-level-number-position:left;
text-indent:-.25in;
font-family:Symbol;}
@list l1:level8
{mso-level-number-format:bullet;
mso-level-text:o;
mso-level-tab-stop:none;
mso-level-number-position:left;
text-indent:-.25in;
font-family:"Courier New";}
@list l1:level9
{mso-level-number-format:bullet;
mso-level-text:\F0A7;
mso-level-tab-stop:none;
mso-level-number-position:left;
text-indent:-.25in;
font-family:Wingdings;}
ol
{margin-bottom:0in;}
ul
{margin-bottom:0in;}
--></style><!--[if gte mso 9]><xml>
<o:shapedefaults v:ext="edit" spidmax="1026" />
</xml><![endif]--><!--[if gte mso 9]><xml>
<o:shapelayout v:ext="edit">
<o:idmap v:ext="edit" data="1" />
</o:shapelayout></xml><![endif]--></head><body lang=EN-US link=blue vlink=purple><div class=WordSection1><p class=MsoNormal><span style='color:#1F497D'>I am still having issues with MANDATORY_IE_MISSING on incoming calls when using FreeTDM + libpri + DAHDI + foneBridge2. Can anyone help me figure out if this is a configuration issue or a bug/incompatibility?<o:p></o:p></span></p><p class=MsoNormal><span style='color:#1F497D'>As stated before, I am running the latest git trunk with all default/stock settings with the exception of FreeTDM configuration and minor modification to the dialplan to pass my DID to the default extension 1001. Outgoing calls are working great.<o:p></o:p></span></p><p class=MsoNormal><span style='color:#1F497D'><o:p> </o:p></span></p><p class=MsoNormal><span style='color:#1F497D'>Below is the debug log from FreeSWITCH with libpri debugging enabled (highlighted in </span><span style='color:red'>RED </span><span style='color:#1F497D'>when the call appears to start failing) –<o:p></o:p></span></p><p class=MsoNormal><span style='color:#1F497D'><o:p> </o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>Dialplan: FreeTDM/1:1/5530 Regex (PASS) [Local_Extension] destination_number(1001) =~ /^(10[01][0-9])$/ break=on-false<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>Dialplan: FreeTDM/1:1/5530 Action export(dialed_extension=1001) <o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>Dialplan: FreeTDM/1:1/5530 Action bind_meta_app(1 b s execute_extension::dx XML features) <o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>Dialplan: FreeTDM/1:1/5530 Action bind_meta_app(2 b s record_session::/usr/local/freeswitch/recordings/${caller_id_number}.${strftime(%Y-%m-%d-%H-%M-%S)}.wav) <o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>Dialplan: FreeTDM/1:1/5530 Action bind_meta_app(3 b s execute_extension::cf XML features) <o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>Dialplan: FreeTDM/1:1/5530 Action bind_meta_app(4 b s execute_extension::att_xfer XML features) <o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>Dialplan: FreeTDM/1:1/5530 Action set(ringback=${us-ring}) <o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>Dialplan: FreeTDM/1:1/5530 Action set(transfer_ringback=local_stream://moh) <o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>Dialplan: FreeTDM/1:1/5530 Action set(call_timeout=30) <o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>Dialplan: FreeTDM/1:1/5530 Action set(hangup_after_bridge=true) <o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>Dialplan: FreeTDM/1:1/5530 Action set(continue_on_fail=true) <o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>Dialplan: FreeTDM/1:1/5530 Action hash(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_number}) <o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>Dialplan: FreeTDM/1:1/5530 Action hash(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid}) <o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>Dialplan: FreeTDM/1:1/5530 Action set(called_party_callgroup=${user_data(${dialed_extension}@${domain_name} var callgroup)}) <o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>Dialplan: FreeTDM/1:1/5530 Action hash(insert/${domain_name}-last_dial_ext/${called_party_callgroup}/${uuid}) <o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>Dialplan: FreeTDM/1:1/5530 Action hash(insert/${domain_name}-last_dial_ext/global/${uuid}) <o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>Dialplan: FreeTDM/1:1/5530 Action hash(insert/${domain_name}-last_dial/${called_party_callgroup}/${uuid}) <o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>Dialplan: FreeTDM/1:1/5530 Action bridge(user/${dialed_extension}@${domain_name}) <o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>Dialplan: FreeTDM/1:1/5530 Action answer() <o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>Dialplan: FreeTDM/1:1/5530 Action sleep(1000) <o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>Dialplan: FreeTDM/1:1/5530 Action bridge(loopback/app=voicemail:default ${domain_name} ${dialed_extension}) <o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.487064 [DEBUG] switch_core_state_machine.c:154 (FreeTDM/1:1/5530) State Change CS_ROUTING -> CS_EXECUTE<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.487064 [DEBUG] switch_core_session.c:1180 Send signal FreeTDM/1:1/5530 [BREAK]<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.487064 [DEBUG] switch_core_state_machine.c:410 (FreeTDM/1:1/5530) State ROUTING going to sleep<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.487064 [DEBUG] switch_core_state_machine.c:362 (FreeTDM/1:1/5530) Running State Change CS_EXECUTE<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.487064 [DEBUG] switch_core_state_machine.c:417 (FreeTDM/1:1/5530) State EXECUTE<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.487064 [DEBUG] mod_freetdm.c:478 FreeTDM/1:1/5530 CHANNEL EXECUTE<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.487064 [DEBUG] switch_core_state_machine.c:192 FreeTDM/1:1/5530 Standard EXECUTE<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>EXECUTE FreeTDM/1:1/5530 set(open=true)<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.487064 [DEBUG] mod_dptools.c:1281 FreeTDM/1:1/5530 SET [open]=[true]<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>EXECUTE FreeTDM/1:1/5530 hash(insert/xx.xx.xx.xxx-spymap/**********/ce58b396-3b2a-11e1-b7d4-9d287cd8ddec)<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>EXECUTE FreeTDM/1:1/5530 hash(insert/xx.xx.xx.xxx-last_dial/**********/1001)<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>EXECUTE FreeTDM/1:1/5530 hash(insert/xx.xx.xx.xxx-last_dial/global/ce58b396-3b2a-11e1-b7d4-9d287cd8ddec)<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>EXECUTE FreeTDM/1:1/5530 set(RFC2822_DATE=Mon, 09 Jan 2012 18:31:23 -0700)<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.487064 [DEBUG] mod_dptools.c:1281 FreeTDM/1:1/5530 SET [RFC2822_DATE]=[Mon, 09 Jan 2012 18:31:23 -0700]<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>EXECUTE FreeTDM/1:1/5530 export(dialed_extension=1001)<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.487064 [DEBUG] switch_channel.c:1091 EXPORT (export_vars) [dialed_extension]=[1001]<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>EXECUTE FreeTDM/1:1/5530 bind_meta_app(1 b s execute_extension::dx XML features)<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.487064 [INFO] switch_ivr_async.c:3179 Bound B-Leg: *1 execute_extension::dx XML features<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>EXECUTE FreeTDM/1:1/5530 bind_meta_app(2 b s record_session::/usr/local/freeswitch/recordings/**********.2012-01-09-18-31-23.wav)<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.487064 [INFO] switch_ivr_async.c:3179 Bound B-Leg: *2 record_session::/usr/local/freeswitch/recordings/**********.2012-01-09-18-31-23.wav<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>EXECUTE FreeTDM/1:1/5530 bind_meta_app(3 b s execute_extension::cf XML features)<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.487064 [INFO] switch_ivr_async.c:3179 Bound B-Leg: *3 execute_extension::cf XML features<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>EXECUTE FreeTDM/1:1/5530 bind_meta_app(4 b s execute_extension::att_xfer XML features)<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.487064 [INFO] switch_ivr_async.c:3179 Bound B-Leg: *4 execute_extension::att_xfer XML features<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>EXECUTE FreeTDM/1:1/5530 set(ringback=%(2000,4000,440,480))<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.487064 [DEBUG] mod_dptools.c:1281 FreeTDM/1:1/5530 SET [ringback]=[%(2000,4000,440,480)]<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>EXECUTE FreeTDM/1:1/5530 set(transfer_ringback=local_stream://moh)<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.487064 [DEBUG] mod_dptools.c:1281 FreeTDM/1:1/5530 SET [transfer_ringback]=[local_stream://moh]<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>EXECUTE FreeTDM/1:1/5530 set(call_timeout=30)<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.487064 [DEBUG] mod_dptools.c:1281 FreeTDM/1:1/5530 SET [call_timeout]=[30]<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>EXECUTE FreeTDM/1:1/5530 set(hangup_after_bridge=true)<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.487064 [DEBUG] mod_dptools.c:1281 FreeTDM/1:1/5530 SET [hangup_after_bridge]=[true]<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>EXECUTE FreeTDM/1:1/5530 set(continue_on_fail=true)<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.487064 [DEBUG] mod_dptools.c:1281 FreeTDM/1:1/5530 SET [continue_on_fail]=[true]<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>EXECUTE FreeTDM/1:1/5530 hash(insert/xx.xx.xx.xxx-call_return/1001/**********)<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>EXECUTE FreeTDM/1:1/5530 hash(insert/xx.xx.xx.xxx-last_dial_ext/1001/ce58b396-3b2a-11e1-b7d4-9d287cd8ddec)<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>EXECUTE FreeTDM/1:1/5530 set(called_party_callgroup=techsupport)<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.487064 [DEBUG] mod_dptools.c:1281 FreeTDM/1:1/5530 SET [called_party_callgroup]=[techsupport]<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>EXECUTE FreeTDM/1:1/5530 hash(insert/xx.xx.xx.xxx-last_dial_ext/techsupport/ce58b396-3b2a-11e1-b7d4-9d287cd8ddec)<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>EXECUTE FreeTDM/1:1/5530 hash(insert/xx.xx.xx.xxx-last_dial_ext/global/ce58b396-3b2a-11e1-b7d4-9d287cd8ddec)<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>EXECUTE FreeTDM/1:1/5530 hash(insert/xx.xx.xx.xxx-last_dial/techsupport/ce58b396-3b2a-11e1-b7d4-9d287cd8ddec)<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>EXECUTE FreeTDM/1:1/5530 bridge(user/1001@xx.xx.xx.xxx)<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.487064 [DEBUG] switch_channel.c:1045 FreeTDM/1:1/5530 EXPORTING[export_vars] [dialed_extension]=[1001] to event<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.487064 [DEBUG] switch_ivr_originate.c:1884 Parsing global variables<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.487064 [DEBUG] switch_channel.c:1045 FreeTDM/1:1/5530 EXPORTING[export_vars] [dialed_extension]=[1001] to event<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.487064 [DEBUG] switch_ivr_originate.c:1884 Parsing global variables<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.487064 [DEBUG] switch_event.c:1521 Parsing variable [sip_invite_domain]=[xx.xx.xx.xxx]<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.487064 [DEBUG] switch_event.c:1521 Parsing variable [presence_id]=[1001@xx.xx.xx.xxx]<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.487064 [NOTICE] switch_channel.c:924 New Channel sofia/internal/sip:1001@xx.xx.xx.xxx:60440 [ce61ab90-3b2a-11e1-b7db-9d287cd8ddec]<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.487064 [DEBUG] mod_sofia.c:4674 (sofia/internal/sip:1001@xx.xx.xx.xxx:60440) State Change CS_NEW -> CS_INIT<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.487064 [DEBUG] switch_core_session.c:1180 Send signal sofia/internal/sip:1001@xx.xx.xx.xxx:60440 [BREAK]<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.487064 [DEBUG] switch_core_state_machine.c:362 (sofia/internal/sip:1001@xx.xx.xx.xxx:60440) Running State Change CS_INIT<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.487064 [DEBUG] switch_core_state_machine.c:401 (sofia/internal/sip:1001@xx.xx.xx.xxx:60440) State INIT<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.487064 [DEBUG] mod_sofia.c:85 sofia/internal/sip:1001@xx.xx.xx.xxx:60440 SOFIA INIT<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.487064 [DEBUG] mod_sofia.c:125 (sofia/internal/sip:1001@xx.xx.xx.xxx:60440) State Change CS_INIT -> CS_ROUTING<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.487064 [DEBUG] switch_core_session.c:1180 Send signal sofia/internal/sip:1001@xx.xx.xx.xxx:60440 [BREAK]<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.487064 [DEBUG] switch_core_state_machine.c:401 (sofia/internal/sip:1001@xx.xx.xx.xxx:60440) State INIT going to sleep<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.487064 [DEBUG] switch_core_state_machine.c:362 (sofia/internal/sip:1001@xx.xx.xx.xxx:60440) Running State Change CS_ROUTING<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.487064 [DEBUG] switch_channel.c:1884 (sofia/internal/sip:1001@xx.xx.xx.xxx:60440) Callstate Change DOWN -> RINGING<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.487064 [DEBUG] switch_core_session.c:875 Send signal sofia/internal/sip:1001@xx.xx.xx.xxx:60440 [BREAK]<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.487064 [DEBUG] switch_core_state_machine.c:410 (sofia/internal/sip:1001@xx.xx.xx.xxx:60440) State ROUTING<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.487064 [DEBUG] mod_sofia.c:148 sofia/internal/sip:1001@xx.xx.xx.xxx:60440 SOFIA ROUTING<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.487064 [DEBUG] switch_ivr_originate.c:66 (sofia/internal/sip:1001@xx.xx.xx.xxx:60440) State Change CS_ROUTING -> CS_CONSUME_MEDIA<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.487064 [DEBUG] switch_core_session.c:1180 Send signal sofia/internal/sip:1001@xx.xx.xx.xxx:60440 [BREAK]<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.487064 [DEBUG] switch_core_state_machine.c:410 (sofia/internal/sip:1001@xx.xx.xx.xxx:60440) State ROUTING going to sleep<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.487064 [DEBUG] switch_core_state_machine.c:362 (sofia/internal/sip:1001@xx.xx.xx.xxx:60440) Running State Change CS_CONSUME_MEDIA<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.487064 [DEBUG] switch_core_state_machine.c:429 (sofia/internal/sip:1001@xx.xx.xx.xxx:60440) State CONSUME_MEDIA<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.487064 [DEBUG] switch_core_state_machine.c:429 (sofia/internal/sip:1001@xx.xx.xx.xxx:60440) State CONSUME_MEDIA going to sleep<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.487064 [DEBUG] sofia.c:5482 Channel sofia/internal/sip:1001@xx.xx.xx.xxx:60440 entering state [calling][0]<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.566904 [DEBUG] switch_core_session.c:875 Send signal sofia/internal/sip:1001@xx.xx.xx.xxx:60440 [BREAK]<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.566904 [DEBUG] switch_core_session.c:875 Send signal sofia/internal/sip:1001@xx.xx.xx.xxx:60440 [BREAK]<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.586909 [DEBUG] sofia.c:5482 Channel sofia/internal/sip:1001@xx.xx.xx.xxx:60440 entering state [proceeding][180]<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.586909 [NOTICE] sofia.c:5574 Ring-Ready sofia/internal/sip:1001@xx.xx.xx.xxx:60440!<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.586909 [DEBUG] mod_freetdm.c:970 [s1c1][1:1] Indicating PROGRESS_MEDIA in state PROCEED<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.586909 [DEBUG] mod_freetdm.c:970 [s1c1][1:1] Changed state from PROCEED to PROGRESS<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.586909 [DEBUG] ftdm_state.c:511 [s1c1][1:1] Executing state processor for PROGRESS<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.586909 [DEBUG] ftmod_libpri.c:679 -- 1:1 STATE [PROGRESS]<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.586909 [DEBUG] ftmod_libpri.c:687 [s1c1][1:1] Completed state change from PROCEED to PROGRESS in 13ms<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.586909 [ERR] ftmod_libpri.c:132 XXX Progress message requested but no information is provided<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.586909 [DEBUG] ftmod_libpri.c:150 <o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.586909 [DEBUG] ftmod_libpri.c:150 > DL-DATA request<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.586909 [DEBUG] ftmod_libpri.c:150 > Protocol Discriminator: Q.931 (8) len=5<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.586909 [DEBUG] ftmod_libpri.c:150 > TEI=0 Call Ref: len= 2 (reference 5073/0x13D1) (Sent to originator)<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.586909 [DEBUG] ftmod_libpri.c:150 > Message Type: PROGRESS (3)<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.586909 [DEBUG] ftmod_libpri.c:150 <o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.586909 [DEBUG] ftmod_libpri.c:150 > Protocol Discriminator: Q.931 (8) len=5<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.586909 [DEBUG] ftmod_libpri.c:150 > TEI=0 Call Ref: len= 2 (reference 5073/0x13D1) (Sent to originator)<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.586909 [DEBUG] ftmod_libpri.c:150 > Message Type: PROGRESS (3)<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.586909 [DEBUG] mod_freetdm.c:970 [s1c1][1:1] Changed state from PROGRESS to PROGRESS_MEDIA<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.646919 [DEBUG] ftdm_state.c:511 [s1c1][1:1] Executing state processor for PROGRESS_MEDIA<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.646919 [DEBUG] ftmod_libpri.c:679 -- 1:1 STATE [PROGRESS_MEDIA]<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.646919 [DEBUG] ftmod_libpri.c:687 [s1c1][1:1] Completed state change from PROGRESS to PROGRESS_MEDIA in 55ms<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.646919 [INFO] ftmod_zt.c:656 Setting echo cancel to 64 taps for 1:1<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.646919 [WARNING] ftmod_zt.c:661 Echo cancel not available for 1:1<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.646919 [DEBUG] ftmod_libpri.c:150 <o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.646919 [DEBUG] ftmod_libpri.c:150 > DL-DATA request<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.646919 [DEBUG] ftmod_libpri.c:150 > Protocol Discriminator: Q.931 (8) len=9<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.646919 [DEBUG] ftmod_libpri.c:150 > TEI=0 Call Ref: len= 2 (reference 5073/0x13D1) (Sent to originator)<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.646919 [DEBUG] ftmod_libpri.c:150 > Message Type: PROGRESS (3)<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.646919 [DEBUG] ftmod_libpri.c:150 <o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.646919 [DEBUG] ftmod_libpri.c:150 > Protocol Discriminator: Q.931 (8) len=9<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.646919 [DEBUG] ftmod_libpri.c:150 > TEI=0 Call Ref: len= 2 (reference 5073/0x13D1) (Sent to originator)<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.646919 [DEBUG] ftmod_libpri.c:150 > Message Type: PROGRESS (3)<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.646919 [DEBUG] ftmod_libpri.c:150 > [1e 02 81 88]<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.646919 [DEBUG] ftmod_libpri.c:150 > Progress Indicator (len= 4) [ Ext: 1 Coding: CCITT (ITU) standard (0) 0: 0 Location: Private network serving the local user (1)<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.646919 [DEBUG] ftmod_libpri.c:150 > Ext: 1 Progress Description: Inband information or appropriate pattern now available. (8) ]<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.646919 [DEBUG] switch_core_session.c:729 Send signal FreeTDM/1:1/5530 [BREAK]<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.646919 [NOTICE] switch_ivr_originate.c:1115 Pre-Answer FreeTDM/1:1/5530!<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.646919 [DEBUG] switch_channel.c:2930 (FreeTDM/1:1/5530) Callstate Change RINGING -> EARLY<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.646919 [DEBUG] switch_ivr_originate.c:1164 Raw Codec Activation Success L16@8000hz 1 channel 20ms<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.646919 [DEBUG] switch_core_codec.c:116 FreeTDM/1:1/5530 Push codec L16:70<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.646919 [DEBUG] switch_ivr_originate.c:1227 Play Ringback Tone [%(2000,4000,440,480)]<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.726904 [DEBUG] ftmod_libpri.c:150 <o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif"'>2012-01-09 18:31:23.726904 [DEBUG] ftmod_libpri.c:150 < Protocol Discriminator: Q.931 (8) len=10<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] ftmod_libpri.c:150 < TEI=0 Call Ref: len= 2 (reference 5073/0x13D1) (Sent from originator)<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] ftmod_libpri.c:150 < Message Type: DISCONNECT (69)<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] ftmod_libpri.c:150 < [08 03 80 e0 1e]<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] ftmod_libpri.c:150 < Cause (len= 5) [ Ext: 1 Coding: CCITT (ITU) standard (0) Spare: 0 Location: User (0)<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] ftmod_libpri.c:150 < Ext: 1 Cause: Mandatory information element is missing (96), class = Protocol Error (e.g. unknown message) (6) ]<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] ftmod_libpri.c:150 < Cause data 1: 1e (30)<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] ftmod_libpri.c:150 Received message for call 0x9ff3790 on link 0x9f8403c TEI/SAPI 0/0<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] ftmod_libpri.c:150 -- Processing IE 8 (cs0, Cause)<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] ftmod_libpri.c:150 -- Found active call: 0x9ff3790 cref:5073<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] ftmod_libpri.c:150 q931.c:8707 post_handle_q931_message: Call 5073 enters state 12 (Disconnect Indication). Hold state: Idle<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] ftmod_libpri.c:1065 -- Hangup REQ on channel 1:1<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] ftmod_libpri.c:150 q931.c:6837 q931_hangup: Hangup other cref:5073<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] ftmod_libpri.c:150 q931.c:6594 __q931_hangup: ourstate Disconnect Indication, peerstate Disconnect Request, hold-state Idle<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] ftmod_libpri.c:150 q931.c:5703 q931_release: Call 5073 enters state 19 (Release Request). Hold state: Idle<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] ftmod_libpri.c:150 <o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] ftmod_libpri.c:150 > DL-DATA request<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] ftmod_libpri.c:150 > Protocol Discriminator: Q.931 (8) len=9<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] ftmod_libpri.c:150 > TEI=0 Call Ref: len= 2 (reference 5073/0x13D1) (Sent to originator)<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] ftmod_libpri.c:150 > Message Type: RELEASE (77)<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] ftmod_libpri.c:150 <o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] ftmod_libpri.c:150 > Protocol Discriminator: Q.931 (8) len=9<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] ftmod_libpri.c:150 > TEI=0 Call Ref: len= 2 (reference 5073/0x13D1) (Sent to originator)<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] ftmod_libpri.c:150 > Message Type: RELEASE (77)<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] ftmod_libpri.c:150 > [08 02 81 e0]<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] ftmod_libpri.c:150 > Cause (len= 4) [ Ext: 1 Coding: CCITT (ITU) standard (0) Spare: 0 Location: Private network serving the local user (1)<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] ftmod_libpri.c:150 > Ext: 1 Cause: Mandatory information element is missing (96), class = Protocol Error (e.g. unknown message) (6) ]<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] ftmod_libpri.c:1078 [s1c1][1:1] Changed state from PROGRESS_MEDIA to TERMINATING<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] ftdm_state.c:511 [s1c1][1:1] Executing state processor for TERMINATING<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] ftmod_libpri.c:679 -- 1:1 STATE [TERMINATING]<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] ftmod_libpri.c:687 [s1c1][1:1] Completed state change from PROGRESS_MEDIA to TERMINATING in 0ms<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] ftdm_io.c:5565 [s1c1][1:1] Scheduling safety hangup timer<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] mod_freetdm.c:2416 got clear channel sig [STOP]<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] switch_channel.c:2846 (FreeTDM/1:1/5530) Callstate Change EARLY -> HANGUP<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [NOTICE] mod_freetdm.c:2441 Hangup FreeTDM/1:1/5530 [CS_EXECUTE] [MANDATORY_IE_MISSING]<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] switch_channel.c:2869 Send signal FreeTDM/1:1/5530 [KILL]<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] switch_core_session.c:1180 Send signal FreeTDM/1:1/5530 [BREAK]<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] switch_core_codec.c:141 FreeTDM/1:1/5530 Restore previous codec PCMU:0.<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] switch_channel.c:2846 (sofia/internal/sip:1001@xx.xx.xx.xxx:60440) Callstate Change RINGING -> HANGUP<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [NOTICE] switch_ivr_originate.c:3182 Hangup sofia/internal/sip:1001@xx.xx.xx.xxx:60440 [CS_CONSUME_MEDIA] [ORIGINATOR_CANCEL]<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] switch_channel.c:2869 Send signal sofia/internal/sip:1001@xx.xx.xx.xxx:60440 [KILL]<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] switch_core_session.c:1180 Send signal sofia/internal/sip:1001@xx.xx.xx.xxx:60440 [BREAK]<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] switch_core_state_machine.c:362 (sofia/internal/sip:1001@xx.xx.xx.xxx:60440) Running State Change CS_HANGUP<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] switch_ivr_originate.c:3358 Originate Cancelled by originator termination Cause: 487 [ORIGINATOR_CANCEL]<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [NOTICE] switch_ivr_originate.c:2459 Cannot create outgoing channel of type [user] cause: [ORIGINATOR_CANCEL]<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] switch_ivr_originate.c:3364 Originate Resulted in Error Cause: 487 [ORIGINATOR_CANCEL]<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [INFO] mod_dptools.c:2900 Originate Failed. Cause: ORIGINATOR_CANCEL<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] switch_core_session.c:2285 FreeTDM/1:1/5530 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] switch_core_state_machine.c:417 (FreeTDM/1:1/5530) State EXECUTE going to sleep<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] switch_core_state_machine.c:362 (FreeTDM/1:1/5530) Running State Change CS_HANGUP<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] switch_core_state_machine.c:602 (sofia/internal/sip:1001@xx.xx.xx.xxx:60440) State HANGUP<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] mod_sofia.c:469 Channel sofia/internal/sip:1001@xx.xx.xx.xxx:60440 hanging up, cause: ORIGINATOR_CANCEL<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] switch_core_state_machine.c:602 (FreeTDM/1:1/5530) State HANGUP<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] mod_freetdm.c:530 [1:1] FreeTDM/1:1/5530 CHANNEL HANGUP ENTER<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] mod_freetdm.c:605 [s1c1][1:1] Changed state from TERMINATING to HANGUP<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] mod_sofia.c:523 Sending CANCEL to sofia/internal/sip:1001@xx.xx.xx.xxx:60440<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] switch_core_state_machine.c:47 sofia/internal/sip:1001@xx.xx.xx.xxx:60440 Standard HANGUP, cause: ORIGINATOR_CANCEL<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] switch_core_state_machine.c:602 (sofia/internal/sip:1001@xx.xx.xx.xxx:60440) State HANGUP going to sleep<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] switch_core_state_machine.c:393 (sofia/internal/sip:1001@xx.xx.xx.xxx:60440) State Change CS_HANGUP -> CS_REPORTING<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] switch_core_session.c:1180 Send signal sofia/internal/sip:1001@xx.xx.xx.xxx:60440 [BREAK]<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] switch_core_state_machine.c:362 (sofia/internal/sip:1001@xx.xx.xx.xxx:60440) Running State Change CS_REPORTING<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/sip:1001@xx.xx.xx.xxx:60440) State REPORTING<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] switch_core_state_machine.c:79 sofia/internal/sip:1001@xx.xx.xx.xxx:60440 Standard REPORTING, cause: ORIGINATOR_CANCEL<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/sip:1001@xx.xx.xx.xxx:60440) State REPORTING going to sleep<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] switch_core_state_machine.c:387 (sofia/internal/sip:1001@xx.xx.xx.xxx:60440) State Change CS_REPORTING -> CS_DESTROY<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] switch_core_session.c:1180 Send signal sofia/internal/sip:1001@xx.xx.xx.xxx:60440 [BREAK]<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] switch_core_session.c:1380 Session 2 (sofia/internal/sip:1001@xx.xx.xx.xxx:60440) Locked, Waiting on external entities<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [NOTICE] switch_core_session.c:1398 Session 2 (sofia/internal/sip:1001@xx.xx.xx.xxx:60440) Ended<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [NOTICE] switch_core_session.c:1400 Close Channel sofia/internal/sip:1001@xx.xx.xx.xxx:60440 [CS_DESTROY]<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] switch_core_state_machine.c:491 (sofia/internal/sip:1001@xx.xx.xx.xxx:60440) Callstate Change HANGUP -> DOWN<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] switch_core_state_machine.c:494 (sofia/internal/sip:1001@xx.xx.xx.xxx:60440) Running State Change CS_DESTROY<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] switch_core_state_machine.c:504 (sofia/internal/sip:1001@xx.xx.xx.xxx:60440) State DESTROY<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] mod_sofia.c:374 sofia/internal/sip:1001@xx.xx.xx.xxx:60440 SOFIA DESTROY<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] switch_core_state_machine.c:86 sofia/internal/sip:1001@xx.xx.xx.xxx:60440 Standard DESTROY<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.726904 [DEBUG] switch_core_state_machine.c:504 (sofia/internal/sip:1001@xx.xx.xx.xxx:60440) State DESTROY going to sleep<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.786903 [DEBUG] ftdm_state.c:511 [s1c1][1:1] Executing state processor for HANGUP<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.786903 [DEBUG] ftmod_libpri.c:679 -- 1:1 STATE [HANGUP]<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.786903 [DEBUG] ftmod_libpri.c:687 [s1c1][1:1] Completed state change from TERMINATING to HANGUP in 52ms<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.786903 [DEBUG] ftmod_libpri.c:150 q931.c:6837 q931_hangup: Hangup other cref:5073<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.786903 [DEBUG] ftmod_libpri.c:150 q931.c:6594 __q931_hangup: ourstate Release Request, peerstate Disconnect Request, hold-state Idle<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.786903 [DEBUG] ftmod_libpri.c:929 [s1c1][1:1] Changed state from HANGUP to HANGUP_COMPLETE<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.786903 [DEBUG] ftdm_state.c:511 [s1c1][1:1] Executing state processor for HANGUP_COMPLETE<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.786903 [DEBUG] ftmod_libpri.c:679 -- 1:1 STATE [HANGUP_COMPLETE]<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.786903 [DEBUG] ftmod_libpri.c:687 [s1c1][1:1] Completed state change from HANGUP to HANGUP_COMPLETE in 0ms<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.786903 [DEBUG] ftmod_libpri.c:939 [s1c1][1:1] Changed state from HANGUP_COMPLETE to DOWN<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.786903 [DEBUG] ftdm_state.c:511 [s1c1][1:1] Executing state processor for DOWN<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.786903 [DEBUG] ftmod_libpri.c:679 -- 1:1 STATE [DOWN]<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.786903 [DEBUG] ftmod_libpri.c:687 [s1c1][1:1] Completed state change from HANGUP_COMPLETE to DOWN in 0ms<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.786903 [DEBUG] ftmod_libpri.c:150 Destroying call 0x9ff3790, ourstate Release Request, peerstate Disconnect Request, hold-state Idle<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.786903 [DEBUG] ftdm_io.c:2930 [s1c1][1:1] DTMF debug is already disabled<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.786903 [DEBUG] ftdm_io.c:2962 [s1c1][1:1] No need to disable input dump<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.786903 [DEBUG] ftdm_io.c:2993 [s1c1][1:1] No need to disable output dump<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.786903 [DEBUG] mod_freetdm.c:2416 got clear channel sig [RELEASED]<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.786903 [DEBUG] ftdm_io.c:6185 Cleared call with id 1<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.786903 [DEBUG] ftdm_io.c:2735 [s1c1][1:1] channel done<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.786903 [DEBUG] ftmod_libpri.c:704 -- Closed channel 1:1<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.786903 [DEBUG] mod_freetdm.c:624 [1:1] FreeTDM/1:1/5530 CHANNEL HANGUP EXIT<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.786903 [DEBUG] switch_core_state_machine.c:47 FreeTDM/1:1/5530 Standard HANGUP, cause: MANDATORY_IE_MISSING<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.786903 [DEBUG] switch_core_state_machine.c:602 (FreeTDM/1:1/5530) State HANGUP going to sleep<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.786903 [DEBUG] switch_core_state_machine.c:393 (FreeTDM/1:1/5530) State Change CS_HANGUP -> CS_REPORTING<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.786903 [DEBUG] switch_core_session.c:1180 Send signal FreeTDM/1:1/5530 [BREAK]<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.786903 [DEBUG] switch_core_state_machine.c:362 (FreeTDM/1:1/5530) Running State Change CS_REPORTING<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.786903 [DEBUG] switch_core_state_machine.c:662 (FreeTDM/1:1/5530) State REPORTING<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.786903 [DEBUG] switch_core_state_machine.c:79 FreeTDM/1:1/5530 Standard REPORTING, cause: MANDATORY_IE_MISSING<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.786903 [DEBUG] switch_core_state_machine.c:662 (FreeTDM/1:1/5530) State REPORTING going to sleep<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.786903 [DEBUG] switch_core_state_machine.c:387 (FreeTDM/1:1/5530) State Change CS_REPORTING -> CS_DESTROY<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.786903 [DEBUG] switch_core_session.c:1180 Send signal FreeTDM/1:1/5530 [BREAK]<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.786903 [DEBUG] switch_core_session.c:1380 Session 1 (FreeTDM/1:1/5530) Locked, Waiting on external entities<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.786903 [NOTICE] switch_core_session.c:1398 Session 1 (FreeTDM/1:1/5530) Ended<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.786903 [NOTICE] switch_core_session.c:1400 Close Channel FreeTDM/1:1/5530 [CS_DESTROY]<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.786903 [DEBUG] switch_core_state_machine.c:491 (FreeTDM/1:1/5530) Callstate Change HANGUP -> DOWN<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.786903 [DEBUG] switch_core_state_machine.c:494 (FreeTDM/1:1/5530) Running State Change CS_DESTROY<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.786903 [DEBUG] switch_core_state_machine.c:504 (FreeTDM/1:1/5530) State DESTROY<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.786903 [DEBUG] switch_core_state_machine.c:86 FreeTDM/1:1/5530 Standard DESTROY<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.786903 [DEBUG] switch_core_state_machine.c:504 (FreeTDM/1:1/5530) State DESTROY going to sleep<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.826906 [DEBUG] ftmod_libpri.c:150 <o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.826906 [DEBUG] ftmod_libpri.c:150 < Protocol Discriminator: Q.931 (8) len=5<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.826906 [DEBUG] ftmod_libpri.c:150 < TEI=0 Call Ref: len= 2 (reference 5073/0x13D1) (Sent from originator)<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.826906 [DEBUG] ftmod_libpri.c:150 < Message Type: RELEASE COMPLETE (90)<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.826906 [DEBUG] ftmod_libpri.c:150 -- Making new call for cref 5073<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.826906 [DEBUG] ftmod_libpri.c:150 Received message for call 0xb6a10b50 on link 0x9f8403c TEI/SAPI 0/0<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.826906 [DEBUG] ftmod_libpri.c:150 q931.c:6837 q931_hangup: Hangup other cref:5073<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.826906 [DEBUG] ftmod_libpri.c:150 q931.c:6594 __q931_hangup: ourstate Null, peerstate Null, hold-state Idle<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:12.0pt;font-family:"Times New Roman","serif";color:red'>2012-01-09 18:31:23.826906 [DEBUG] ftmod_libpri.c:150 Destroying call 0xb6a10b50, ourstate Null, peerstate Null, hold-state Idle<o:p></o:p></span></p><p class=MsoNormal><span style='color:#1F497D'><o:p> </o:p></span></p><p class=MsoPlainText>I’ve posted the full log (from starting FreeSWITCH to incoming call failure) at - <a href="http://pastebin.com/QaBqbCgU">http://pastebin.com/QaBqbCgU</a><o:p></o:p></p><p class=MsoNormal><span style='color:#1F497D'><o:p> </o:p></span></p><p class=MsoNormal><span style='color:#1F497D'>You can see my configuration files in the original e-mail below.<o:p></o:p></span></p><p class=MsoNormal><span style='color:#1F497D'><o:p> </o:p></span></p><p class=MsoNormal><span style='color:#1F497D'>Thanks in advance if anyone is able to help. This is my last attempt before settling with FreeSWITCH 1.0.6 + OpenZAP(already working in production) instead of lastest + FreeTDM.<o:p></o:p></span></p><p class=MsoNormal><span style='color:#1F497D'><o:p> </o:p></span></p><p class=MsoNormal><span style='color:#1F497D'>-Adam<o:p></o:p></span></p><p class=MsoNormal><span style='color:#1F497D'><o:p> </o:p></span></p><p class=MsoNormal><span style='color:#1F497D'><o:p> </o:p></span></p><div><div style='border:none;border-top:solid #B5C4DF 1.0pt;padding:3.0pt 0in 0in 0in'><p class=MsoNormal><b><span style='font-size:10.0pt;font-family:"Tahoma","sans-serif"'>From:</span></b><span style='font-size:10.0pt;font-family:"Tahoma","sans-serif"'> freeswitch-users-bounces@lists.freeswitch.org [mailto:freeswitch-users-bounces@lists.freeswitch.org] <b>On Behalf Of </b>Adam Ford<br><b>Sent:</b> Sunday, January 08, 2012 6:33 PM<br><b>To:</b> FreeSWITCH-users@lists.freeswitch.org<br><b>Subject:</b> [Freeswitch-users] FreeTDM [MANDATORY_IE_MISSING]<o:p></o:p></span></p></div></div><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>I can’t seem to find any info on the problem I am having by searching the archives, so I apologize if this has been answered in the past (found several about MANDATORY_IE_MISSING but they were different situations).<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>I am trying to setup FreeSWITCH using a FreeTDM + libpri + DAHDI + foneBridge2 stack. Outgoing calls work great, but I am running into the ‘MANDATORY_IE_MISSING’ problem with incoming calls. I am running the latest git version as of this morning, and completely default configuration with the exception of FreeTDM/DAHDI configuration and a modification of the default inbound_did dialplan to pass my DID 5530 to the default extension 1001.<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>Below is what I get in the log, I highlighted in <span style='color:#C00000'>RED</span> as soon as the call appears to start failing -<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal><span style='color:#1F497D'><replaced with above></span> <o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>freeswitch/conf/freetdm.conf – <o:p></o:p></p><p class=MsoNormal>[span zt PRI]<o:p></o:p></p><p class=MsoNormal>trunk_type => T1<o:p></o:p></p><p class=MsoNormal>b-channel=1-23<o:p></o:p></p><p class=MsoNormal>d-channel=24<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>freeswitch/conf/autoload_confg/freetdm.conf.xml –<o:p></o:p></p><p class=MsoNormal><configuration name="freetdm.conf" description="FreeTDM Configuration"><o:p></o:p></p><p class=MsoNormal> <settings><o:p></o:p></p><p class=MsoNormal> <param name="debug" value="1"/><o:p></o:p></p><p class=MsoNormal> </settings><o:p></o:p></p><p class=MsoNormal> <libpri_spans><o:p></o:p></p><p class=MsoNormal> <span name="PRI"><o:p></o:p></p><p class=MsoNormal> <param name="node" value="cpe"/><o:p></o:p></p><p class=MsoNormal> <param name="switch" value="ni2"/><o:p></o:p></p><p class=MsoNormal> <param name="dialplan" value="XML"/><o:p></o:p></p><p class=MsoNormal> <param name="context" value="public"/><o:p></o:p></p><p class=MsoNormal> <param name="l1" value="ulaw"/><o:p></o:p></p><p class=MsoNormal> </span><o:p></o:p></p><p class=MsoNormal> </libpri_spans><o:p></o:p></p><p class=MsoNormal></configuration><o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>/etc/dahdi/system.conf –<o:p></o:p></p><p class=MsoNormal>loadzone = us<o:p></o:p></p><p class=MsoNormal>defaultzone=us<o:p></o:p></p><p class=MsoNormal>dynamic=ethmf,eth0/00:50:c2:65:d7:59/0,24,1<o:p></o:p></p><p class=MsoNormal>bchan=1-23<o:p></o:p></p><p class=MsoNormal>dchan=24<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>I am guessing it is a configuration issue, though this same config is currently working in production with FreeSWITCH 1.0.6 + OpenZAP + Libpri + DAHDI + foneBridge2.<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>Any help is greatly appreciated.<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>-Adam<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal><o:p> </o:p></p></div></body></html>