Callback fails -

I have set up a CALLBACK on a FreePBX 2.10 Distro installation. The callback has a DISA as destination. After initially setting up the CALLBACKto DISA last week, it worked fine for a couple of days, but now fails to succesfully call back to the remote caller. I have looked at the Asterisk log and i can see that the incoming call on the DID (named MY-DID-NUMBER) is succesfully initiating the callback. After the 1st inbound call ist terminated by my PBX, a call to the original caller is established. Even though it is registered by my SIP provider, the call isn’t established. I hope the following extracion from the log is helpful. Can maybe anyone point me in the right direction where to look at? I’m still very new to Asterisk, but would like to return the favors received … someday :wink:

Here’s the log output for a failed call

[2012-03-26 15:49:57] VERBOSE[-1] netsock2.c: == Using SIP RTP TOS bits 184 [2012-03-26 15:49:57] VERBOSE[-1] netsock2.c: == Using SIP RTP CoS mark 5 [2012-03-26 15:49:57] VERBOSE[-1] pbx.c: -- Executing [MY-DID-NUMER@from-trunk:1] Set("SIP/MY-SIP-ID-0000004d", "__FROM_DID=MY-DID-NUMER") in new stack [2012-03-26 15:49:57] VERBOSE[-1] pbx.c: -- Executing [MY-DID-NUMER@from-trunk:2] Gosub("SIP/MY-SIP-ID-0000004d", "app-blacklist-check,s,1()") in new stack [2012-03-26 15:49:57] VERBOSE[-1] pbx.c: -- Executing [s@app-blacklist-check:1] GotoIf("SIP/MY-SIP-ID-0000004d", "0?blacklisted") in new stack [2012-03-26 15:49:57] VERBOSE[-1] pbx.c: -- Executing [s@app-blacklist-check:2] Set("SIP/MY-SIP-ID-0000004d", "CALLED_BLACKLIST=1") in new stack [2012-03-26 15:49:57] VERBOSE[-1] pbx.c: -- Executing [s@app-blacklist-check:3] Return("SIP/MY-SIP-ID-0000004d", "") in new stack [2012-03-26 15:49:57] VERBOSE[-1] pbx.c: -- Executing [MY-DID-NUMER@from-trunk:3] Set("SIP/MY-SIP-ID-0000004d", "CDR(did)=MY-DID-NUMER") in new stack [2012-03-26 15:49:57] VERBOSE[-1] pbx.c: -- Executing [MY-DID-NUMER@from-trunk:4] ExecIf("SIP/MY-SIP-ID-0000004d", "0 ?Set(CALLERID(name)=THE-NUMBER-TO-CALL)") in new stack [2012-03-26 15:49:57] VERBOSE[-1] pbx.c: -- Executing [MY-DID-NUMER@from-trunk:5] Set("SIP/MY-SIP-ID-0000004d", "__CALLINGPRES_SV=allowed_not_screened") in new stack [2012-03-26 15:49:57] VERBOSE[-1] pbx.c: -- Executing [MY-DID-NUMER@from-trunk:6] Set("SIP/MY-SIP-ID-0000004d", "CALLERPRES()=allowed_not_screened") in new stack [2012-03-26 15:49:57] VERBOSE[-1] pbx.c: -- Executing [MY-DID-NUMER@from-trunk:7] Goto("SIP/MY-SIP-ID-0000004d", "callback,2,1") in new stack [2012-03-26 15:49:57] VERBOSE[-1] pbx.c: -- Goto (callback,2,1) [2012-03-26 15:49:57] VERBOSE[-1] pbx.c: -- Executing [2@callback:1] Set("SIP/MY-SIP-ID-0000004d", "CALL=THE-NUMBER-TO-CALL") in new stack [2012-03-26 15:49:57] VERBOSE[-1] pbx.c: -- Executing [2@callback:2] Set("SIP/MY-SIP-ID-0000004d", "DESTINATION=disa.4.1") in new stack [2012-03-26 15:49:57] VERBOSE[-1] pbx.c: -- Executing [2@callback:3] Set("SIP/MY-SIP-ID-0000004d", "SLEEP=3") in new stack [2012-03-26 15:49:57] VERBOSE[-1] pbx.c: -- Executing [2@callback:4] System("SIP/MY-SIP-ID-0000004d", "/var/lib/asterisk/bin/callback THE-NUMBER-TO-CALL disa.4.1 3 &") in new stack [2012-03-26 15:49:57] VERBOSE[-1] pbx.c: -- Executing [2@callback:5] Hangup("SIP/MY-SIP-ID-0000004d", "") in new stack [2012-03-26 15:49:57] VERBOSE[-1] pbx.c: == Spawn extension (callback, 2, 5) exited non-zero on 'SIP/MY-SIP-ID-0000004d' [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [THE-NUMBER-TO-CALL@from-internal:1] Macro("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "user-callerid,LIMIT,") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [s@macro-user-callerid:1] Set("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "AMPUSER=") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [s@macro-user-callerid:2] GotoIf("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "0?report") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [s@macro-user-callerid:3] ExecIf("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "1?Set(REALCALLERIDNUM=)") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [s@macro-user-callerid:4] Set("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "AMPUSER=") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [s@macro-user-callerid:5] Set("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "AMPUSERCIDNAME=") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [s@macro-user-callerid:6] GotoIf("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "1?report") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Goto (macro-user-callerid,s,13) [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [s@macro-user-callerid:13] GotoIf("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "1?continue") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Goto (macro-user-callerid,s,26) [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [s@macro-user-callerid:26] Set("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "CALLERID(number)=") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [s@macro-user-callerid:27] Set("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "CALLERID(name)=Callback") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [s@macro-user-callerid:28] Set("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "CHANNEL(language)=en") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [THE-NUMBER-TO-CALL@from-internal:2] Set("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "MOHCLASS=default") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [THE-NUMBER-TO-CALL@from-internal:3] Set("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "_NODEST=") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [THE-NUMBER-TO-CALL@from-internal:4] Gosub("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "sub-record-check,s,1(out,THE-NUMBER-TO-CALL,)") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [s@sub-record-check:1] GotoIf("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "1?check") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Goto (sub-record-check,s,3) [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [s@sub-record-check:3] Set("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "MON_FMT=wav") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [s@sub-record-check:4] GotoIf("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "1?next") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Goto (sub-record-check,s,7) [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [s@sub-record-check:7] ExecIf("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "0?Return()") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [s@sub-record-check:8] GotoIf("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "0?out,1") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [s@sub-record-check:9] Set("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "__REC_STATUS=INITIALIZED") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [s@sub-record-check:10] ExecIf("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "0?Set(__REC_POLICY_MODE=)") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [s@sub-record-check:11] Set("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "NOW=1332769800") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [s@sub-record-check:12] Set("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "__DAY=26") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [s@sub-record-check:13] Set("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "__MONTH=03") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [s@sub-record-check:14] Set("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "__YEAR=2012") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [s@sub-record-check:15] Set("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "__TIMESTR=20120326-155000") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [s@sub-record-check:16] Set("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "__FROMEXTEN=unknown") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [s@sub-record-check:17] Set("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "__CALLFILENAME=out-THE-NUMBER-TO-CALL-unknown-20120326-155000-1332769800.168") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [s@sub-record-check:18] Goto("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "out,1") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Goto (sub-record-check,out,1) [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [out@sub-record-check:1] ExecIf("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "1?Set(__REC_POLICY_MODE=)") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [out@sub-record-check:2] GosubIf("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "0?record,1(exten,THE-NUMBER-TO-CALL,unknown)") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [out@sub-record-check:3] Return("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [THE-NUMBER-TO-CALL@from-internal:5] Macro("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "dialout-trunk,1,THE-NUMBER-TO-CALL,") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [s@macro-dialout-trunk:1] Set("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "DIAL_TRUNK=1") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [s@macro-dialout-trunk:2] GosubIf("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "0?sub-pincheck,s,1()") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [s@macro-dialout-trunk:3] GotoIf("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "0?disabletrunk,1") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [s@macro-dialout-trunk:4] Set("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "DIAL_NUMBER=THE-NUMBER-TO-CALL") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [s@macro-dialout-trunk:5] Set("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "DIAL_TRUNK_OPTIONS=tr") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [s@macro-dialout-trunk:6] Set("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "OUTBOUND_GROUP=OUT_1") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [s@macro-dialout-trunk:7] GotoIf("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "1?nomax") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Goto (macro-dialout-trunk,s,9) [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [s@macro-dialout-trunk:9] GotoIf("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "0?skipoutcid") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [s@macro-dialout-trunk:10] Set("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "DIAL_TRUNK_OPTIONS=") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [s@macro-dialout-trunk:11] Macro("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "outbound-callerid,1") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [s@macro-outbound-callerid:1] ExecIf("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "0?Set(CALLERPRES()=)") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [s@macro-outbound-callerid:2] ExecIf("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "1?Set(REALCALLERIDNUM=)") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [s@macro-outbound-callerid:3] GotoIf("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "1?normcid") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Goto (macro-outbound-callerid,s,6) [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [s@macro-outbound-callerid:6] Set("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "USEROUTCID=") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [s@macro-outbound-callerid:7] Set("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "EMERGENCYCID=") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [s@macro-outbound-callerid:8] Set("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "TRUNKOUTCID=") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [s@macro-outbound-callerid:9] GotoIf("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "1?trunkcid") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Goto (macro-outbound-callerid,s,12) [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [s@macro-outbound-callerid:12] ExecIf("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "0?Set(CALLERID(all)=)") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [s@macro-outbound-callerid:13] ExecIf("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "0?Set(CALLERID(all)=)") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [s@macro-outbound-callerid:14] ExecIf("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "0?Set(CALLERID(all)=)") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [s@macro-outbound-callerid:15] ExecIf("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "0?Set(CALLERPRES()=prohib_passed_screen)") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [s@macro-dialout-trunk:12] GosubIf("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "0?sub-flp-1,s,1()") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [s@macro-dialout-trunk:13] Set("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "OUTNUM=THE-NUMBER-TO-CALL") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [s@macro-dialout-trunk:14] Set("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "custom=SIP/MY-SIP-PROVIDER") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [s@macro-dialout-trunk:15] ExecIf("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "0?Set(DIAL_TRUNK_OPTIONS=M(setmusic^default))") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [s@macro-dialout-trunk:16] ExecIf("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "0?Set(DIAL_TRUNK_OPTIONS=M(confirm))") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [s@macro-dialout-trunk:17] Macro("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "dialout-trunk-predial-hook,") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [s@macro-dialout-trunk-predial-hook:1] MacroExit("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [s@macro-dialout-trunk:18] GotoIf("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "0?bypass,1") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [s@macro-dialout-trunk:19] ExecIf("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "0?Set(CONNECTEDLINE(num,i)=THE-NUMBER-TO-CALL)") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [s@macro-dialout-trunk:20] ExecIf("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "0?Set(CONNECTEDLINE(name,i)=CID:)") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [s@macro-dialout-trunk:21] GotoIf("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "0?customtrunk") in new stack [2012-03-26 15:50:00] VERBOSE[-1] pbx.c: -- Executing [s@macro-dialout-trunk:22] Dial("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "SIP/MY-SIP-PROVIDER/THE-NUMBER-TO-CALL,300,") in new stack [2012-03-26 15:50:00] VERBOSE[-1] netsock2.c: == Using SIP RTP TOS bits 184 [2012-03-26 15:50:00] VERBOSE[-1] netsock2.c: == Using SIP RTP CoS mark 5 [2012-03-26 15:50:00] VERBOSE[-1] app_dial.c: -- Called SIP/MY-SIP-PROVIDER/THE-NUMBER-TO-CALL [2012-03-26 15:50:02] VERBOSE[-1] app_dial.c: -- SIP/MY-SIP-PROVIDER-0000004e is making progress passing it to Local/THE-NUMBER-TO-CALL@from-internal-d57f;2 [2012-03-26 15:50:03] VERBOSE[-1] chan_sip.c: -- Got SIP response 486 "Busy here" back from 2xx.xx.xx.xxx:5060 [2012-03-26 15:50:03] VERBOSE[-1] app_dial.c: -- SIP/MY-SIP-PROVIDER-0000004e is busy [2012-03-26 15:50:03] VERBOSE[-1] app_dial.c: == Everyone is busy/congested at this time (1:1/0/0) [2012-03-26 15:50:03] VERBOSE[-1] pbx.c: -- Executing [s@macro-dialout-trunk:23] NoOp("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "Dial failed for some reason with DIALSTATUS = BUSY and HANGUPCAUSE = 17") in new stack [2012-03-26 15:50:03] VERBOSE[-1] pbx.c: -- Executing [s@macro-dialout-trunk:24] Goto("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "s-BUSY,1") in new stack [2012-03-26 15:50:03] VERBOSE[-1] pbx.c: -- Goto (macro-dialout-trunk,s-BUSY,1) [2012-03-26 15:50:03] VERBOSE[-1] pbx.c: -- Executing [s-BUSY@macro-dialout-trunk:1] NoOp("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "Dial failed due to trunk reporting BUSY - giving up") in new stack [2012-03-26 15:50:03] VERBOSE[-1] pbx.c: -- Executing [s-BUSY@macro-dialout-trunk:2] PlayTones("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "busy") in new stack [2012-03-26 15:50:03] VERBOSE[-1] pbx.c: -- Executing [s-BUSY@macro-dialout-trunk:3] Busy("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "20") in new stack [2012-03-26 15:50:03] VERBOSE[-1] app_macro.c: == Spawn extension (macro-dialout-trunk, s-BUSY, 3) exited non-zero on 'Local/THE-NUMBER-TO-CALL@from-internal-d57f;2' in macro 'dialout-trunk' [2012-03-26 15:50:03] VERBOSE[-1] pbx.c: == Spawn extension (from-internal, THE-NUMBER-TO-CALL, 5) exited non-zero on 'Local/THE-NUMBER-TO-CALL@from-internal-d57f;2' [2012-03-26 15:50:03] VERBOSE[-1] pbx.c: -- Executing [h@from-internal:1] Hangup("Local/THE-NUMBER-TO-CALL@from-internal-d57f;2", "") in new stack [2012-03-26 15:50:03] VERBOSE[-1] pbx.c: == Spawn extension (from-internal, h, 1) exited non-zero on 'Local/THE-NUMBER-TO-CALL@from-internal-d57f;2' [2012-03-26 15:50:04] VERBOSE[-1] netsock2.c: == Using SIP RTP TOS bits 184 [2012-03-26 15:50:04] VERBOSE[-1] netsock2.c: == Using SIP RTP CoS mark 5 [2012-03-26 15:50:04] VERBOSE[-1] pbx.c: -- Executing [MY-DID-NUMER@from-trunk:1] Set("SIP/MY-SIP-ID-0000004f", "__FROM_DID=MY-DID-NUMER") in new stack [2012-03-26 15:50:04] VERBOSE[-1] pbx.c: -- Executing [MY-DID-NUMER@from-trunk:2] Gosub("SIP/MY-SIP-ID-0000004f", "app-blacklist-check,s,1()") in new stack [2012-03-26 15:50:04] VERBOSE[-1] pbx.c: -- Executing [s@app-blacklist-check:1] GotoIf("SIP/MY-SIP-ID-0000004f", "0?blacklisted") in new stack [2012-03-26 15:50:04] VERBOSE[-1] pbx.c: -- Executing [s@app-blacklist-check:2] Set("SIP/MY-SIP-ID-0000004f", "CALLED_BLACKLIST=1") in new stack [2012-03-26 15:50:04] VERBOSE[-1] pbx.c: -- Executing [s@app-blacklist-check:3] Return("SIP/MY-SIP-ID-0000004f", "") in new stack [2012-03-26 15:50:04] VERBOSE[-1] pbx.c: -- Executing [MY-DID-NUMER@from-trunk:3] Set("SIP/MY-SIP-ID-0000004f", "CDR(did)=MY-DID-NUMER") in new stack [2012-03-26 15:50:04] VERBOSE[-1] pbx.c: -- Executing [MY-DID-NUMER@from-trunk:4] ExecIf("SIP/MY-SIP-ID-0000004f", "0 ?Set(CALLERID(name)=anonymous)") in new stack [2012-03-26 15:50:04] VERBOSE[-1] pbx.c: -- Executing [MY-DID-NUMER@from-trunk:5] Set("SIP/MY-SIP-ID-0000004f", "__CALLINGPRES_SV=allowed_not_screened") in new stack [2012-03-26 15:50:04] VERBOSE[-1] pbx.c: -- Executing [MY-DID-NUMER@from-trunk:6] Set("SIP/MY-SIP-ID-0000004f", "CALLERPRES()=allowed_not_screened") in new stack [2012-03-26 15:50:04] VERBOSE[-1] pbx.c: -- Executing [MY-DID-NUMER@from-trunk:7] Goto("SIP/MY-SIP-ID-0000004f", "callback,2,1") in new stack [2012-03-26 15:50:04] VERBOSE[-1] pbx.c: -- Goto (callback,2,1) [2012-03-26 15:50:04] VERBOSE[-1] pbx.c: -- Executing [2@callback:1] Set("SIP/MY-SIP-ID-0000004f", "CALL=anonymous") in new stack [2012-03-26 15:50:04] VERBOSE[-1] pbx.c: -- Executing [2@callback:2] Set("SIP/MY-SIP-ID-0000004f", "DESTINATION=disa.4.1") in new stack [2012-03-26 15:50:04] VERBOSE[-1] pbx.c: -- Executing [2@callback:3] Set("SIP/MY-SIP-ID-0000004f", "SLEEP=3") in new stack [2012-03-26 15:50:04] VERBOSE[-1] pbx.c: -- Executing [2@callback:4] System("SIP/MY-SIP-ID-0000004f", "/var/lib/asterisk/bin/callback anonymous disa.4.1 3 &") in new stack [2012-03-26 15:50:04] VERBOSE[-1] pbx.c: -- Executing [2@callback:5] Hangup("SIP/MY-SIP-ID-0000004f", "") in new stack [2012-03-26 15:50:04] VERBOSE[-1] pbx.c: == Spawn extension (callback, 2, 5) exited non-zero on 'SIP/MY-SIP-ID-0000004f' [2012-03-26 15:50:07] NOTICE[-1] chan_local.c: No such extension/context anonymous@from-internal while calling Local channel [2012-03-26 15:50:07] NOTICE[-1] channel.c: Unable to call channel Local/anonymous@from-internal [2012-03-26 15:50:08] VERBOSE[-1] netsock2.c: == Using SIP RTP TOS bits 184 [2012-03-26 15:50:08] VERBOSE[-1] netsock2.c: == Using SIP RTP CoS mark 5 [2012-03-26 15:50:08] VERBOSE[-1] pbx.c: -- Executing [MY-DID-NUMER@from-trunk:1] Set("SIP/MY-SIP-ID-00000050", "__FROM_DID=MY-DID-NUMER") in new stack [2012-03-26 15:50:08] VERBOSE[-1] pbx.c: -- Executing [MY-DID-NUMER@from-trunk:2] Gosub("SIP/MY-SIP-ID-00000050", "app-blacklist-check,s,1()") in new stack [2012-03-26 15:50:08] VERBOSE[-1] pbx.c: -- Executing [s@app-blacklist-check:1] GotoIf("SIP/MY-SIP-ID-00000050", "0?blacklisted") in new stack [2012-03-26 15:50:08] VERBOSE[-1] pbx.c: -- Executing [s@app-blacklist-check:2] Set("SIP/MY-SIP-ID-00000050", "CALLED_BLACKLIST=1") in new stack [2012-03-26 15:50:08] VERBOSE[-1] pbx.c: -- Executing [s@app-blacklist-check:3] Return("SIP/MY-SIP-ID-00000050", "") in new stack [2012-03-26 15:50:08] VERBOSE[-1] pbx.c: -- Executing [MY-DID-NUMER@from-trunk:3] Set("SIP/MY-SIP-ID-00000050", "CDR(did)=MY-DID-NUMER") in new stack [2012-03-26 15:50:08] VERBOSE[-1] pbx.c: -- Executing [MY-DID-NUMER@from-trunk:4] ExecIf("SIP/MY-SIP-ID-00000050", "0 ?Set(CALLERID(name)=anonymous)") in new stack [2012-03-26 15:50:08] VERBOSE[-1] pbx.c: -- Executing [MY-DID-NUMER@from-trunk:5] Set("SIP/MY-SIP-ID-00000050", "__CALLINGPRES_SV=allowed_not_screened") in new stack [2012-03-26 15:50:08] VERBOSE[-1] pbx.c: -- Executing [MY-DID-NUMER@from-trunk:6] Set("SIP/MY-SIP-ID-00000050", "CALLERPRES()=allowed_not_screened") in new stack [2012-03-26 15:50:08] VERBOSE[-1] pbx.c: -- Executing [MY-DID-NUMER@from-trunk:7] Goto("SIP/MY-SIP-ID-00000050", "callback,2,1") in new stack [2012-03-26 15:50:08] VERBOSE[-1] pbx.c: -- Goto (callback,2,1) [2012-03-26 15:50:08] VERBOSE[-1] pbx.c: -- Executing [2@callback:1] Set("SIP/MY-SIP-ID-00000050", "CALL=anonymous") in new stack [2012-03-26 15:50:08] VERBOSE[-1] pbx.c: -- Executing [2@callback:2] Set("SIP/MY-SIP-ID-00000050", "DESTINATION=disa.4.1") in new stack [2012-03-26 15:50:08] VERBOSE[-1] pbx.c: -- Executing [2@callback:3] Set("SIP/MY-SIP-ID-00000050", "SLEEP=3") in new stack [2012-03-26 15:50:08] VERBOSE[-1] pbx.c: -- Executing [2@callback:4] System("SIP/MY-SIP-ID-00000050", "/var/lib/asterisk/bin/callback anonymous disa.4.1 3 &") in new stack [2012-03-26 15:50:08] VERBOSE[-1] pbx.c: -- Executing [2@callback:5] Hangup("SIP/MY-SIP-ID-00000050", "") in new stack [2012-03-26 15:50:08] VERBOSE[-1] pbx.c: == Spawn extension (callback, 2, 5) exited non-zero on 'SIP/MY-SIP-ID-00000050' [2012-03-26 15:50:12] NOTICE[-1] chan_local.c: No such extension/context anonymous@from-internal while calling Local channel [2012-03-26 15:50:12] NOTICE[-1] channel.c: Unable to call channel Local/anonymous@from-internal