Outgoing line is always busy

byrnejb · April 3, 2013, 6:52pm

I am experimenting with the FreePBX distro using Asterisk 11.3.0 and FreePBX 2.11.0.0beta2.8. I am using Twinkle as a softphone for testing. The system this is running on is a former TrixBox rack-mount appliance with an Intel Atom processor and a four port FXO card from Digium, model unknown (to me).

I have configured three devices (extensions) and two users. I can call one extension from another using softphones. I have configured one FXO port as a trunk and have a POTS line patched into it. I have configured an inbound route and I can call into the PBX and pickup the line from the softphone. Other than the echo is terrible this seems to me to be working as intended.

I apologize for not including any configuration details but I have no idea what is significant in this case. I performed all configuration to this point through FreePBX.

What I cannot do at the moment is to place an outgoing call. When I attempt to do so this is what happens:


Connected to Asterisk 11.3.0 currently running on voinet01 (pid = 505)
  == Using SIP VIDEO TOS bits 136
  == Using SIP VIDEO CoS mark 6
  == Using SIP RTP TOS bits 184
  == Using SIP RTP CoS mark 5
    -- Executing [9055611241@from-internal:1] Macro("SIP/41710-0000000c", "user-callerid,LIMIT,") in new stack
    -- Executing [s@macro-user-callerid:1] Set("SIP/41710-0000000c", "TOUCH_MONITOR=1365013819.18") in new stack
    -- Executing [s@macro-user-callerid:2] Set("SIP/41710-0000000c", "AMPUSER=41710") in new stack
    -- Executing [s@macro-user-callerid:3] GotoIf("SIP/41710-0000000c", "0?report") in new stack
    -- Executing [s@macro-user-callerid:4] ExecIf("SIP/41710-0000000c", "1?Set(REALCALLERIDNUM=41710)") in new stack
    -- Executing [s@macro-user-callerid:5] Set("SIP/41710-0000000c", "AMPUSER=41710") in new stack
    -- Executing [s@macro-user-callerid:6] Set("SIP/41710-0000000c", "AMPUSERCIDNAME=Reception") in new stack
    -- Executing [s@macro-user-callerid:7] GotoIf("SIP/41710-0000000c", "0?report") in new stack
    -- Executing [s@macro-user-callerid:8] Set("SIP/41710-0000000c", "AMPUSERCID=41710") in new stack
    -- Executing [s@macro-user-callerid:9] Set("SIP/41710-0000000c", "__DIAL_OPTIONS=Ttr") in new stack
    -- Executing [s@macro-user-callerid:10] Set("SIP/41710-0000000c", "CALLERID(all)="Reception" <41710>") in new stack
    -- Executing [s@macro-user-callerid:11] GotoIf("SIP/41710-0000000c", "0?limit") in new stack
    -- Executing [s@macro-user-callerid:12] ExecIf("SIP/41710-0000000c", "1?Set(GROUP(concurrency_limit)=41710)") in new stack
    -- Executing [s@macro-user-callerid:13] GosubIf("SIP/41710-0000000c", "7?sub-ccss,s,1(from-internal,9055611241)") in new stack
    -- Executing [s@sub-ccss:1] ExecIf("SIP/41710-0000000c", "0?Return()") in new stack
    -- Executing [s@sub-ccss:2] Set("SIP/41710-0000000c", "CCSS_SETUP=TRUE") in new stack
    -- Executing [s@sub-ccss:3] GosubIf("SIP/41710-0000000c", "0?monitor_config,1(from-internal,9055611241):monitor_default,1(from-internal,9055611241)") in new stack
    -- Executing [monitor_default@sub-ccss:1] GotoIf("SIP/41710-0000000c", "0?is_exten") in new stack
    -- Executing [monitor_default@sub-ccss:2] StackPop("SIP/41710-0000000c", "") in new stack
    -- Executing [monitor_default@sub-ccss:3] Return("SIP/41710-0000000c", "FALSE") in new stack
    -- Executing [s@macro-user-callerid:14] ExecIf("SIP/41710-0000000c", "0?Set(CHANNEL(language)=)") in new stack
    -- Executing [s@macro-user-callerid:15] GotoIf("SIP/41710-0000000c", "1?continue") in new stack
    -- Goto (macro-user-callerid,s,28)
    -- Executing [s@macro-user-callerid:28] Set("SIP/41710-0000000c", "CALLERID(number)=41710") in new stack
    -- Executing [s@macro-user-callerid:29] Set("SIP/41710-0000000c", "CALLERID(name)=Reception") in new stack
    -- Executing [s@macro-user-callerid:30] Set("SIP/41710-0000000c", "CDR(cnum)=41710") in new stack
    -- Executing [s@macro-user-callerid:31] Set("SIP/41710-0000000c", "CDR(cnam)=Reception") in new stack
    -- Executing [s@macro-user-callerid:32] Set("SIP/41710-0000000c", "CHANNEL(language)=en") in new stack
    -- Executing [9055611241@from-internal:2] Set("SIP/41710-0000000c", "MOHCLASS=default") in new stack
    -- Executing [9055611241@from-internal:3] ExecIf("SIP/41710-0000000c", "1?Set(TRUNKCIDOVERRIDE=905-561-5731)") in new stack
    -- Executing [9055611241@from-internal:4] Set("SIP/41710-0000000c", "_NODEST=") in new stack
    -- Executing [9055611241@from-internal:5] Gosub("SIP/41710-0000000c", "sub-record-check,s,1(out,9055611241,)") in new stack
    -- Executing [s@sub-record-check:1] Set("SIP/41710-0000000c", "REC_POLICY_MODE_SAVE=") in new stack
    -- Executing [s@sub-record-check:2] GotoIf("SIP/41710-0000000c", "1?check") in new stack
    -- Goto (sub-record-check,s,7)
    -- Executing [s@sub-record-check:7] Set("SIP/41710-0000000c", "__MON_FMT=wav") in new stack
    -- Executing [s@sub-record-check:8] GotoIf("SIP/41710-0000000c", "1?next") in new stack
    -- Goto (sub-record-check,s,11)
    -- Executing [s@sub-record-check:11] ExecIf("SIP/41710-0000000c", "0?Return()") in new stack
    -- Executing [s@sub-record-check:12] ExecIf("SIP/41710-0000000c", "0?Set(__REC_POLICY_MODE=)") in new stack
    -- Executing [s@sub-record-check:13] GotoIf("SIP/41710-0000000c", "0?out,1") in new stack
    -- Executing [s@sub-record-check:14] Set("SIP/41710-0000000c", "__REC_STATUS=INITIALIZED") in new stack
    -- Executing [s@sub-record-check:15] Set("SIP/41710-0000000c", "NOW=1365013819") in new stack
    -- Executing [s@sub-record-check:16] Set("SIP/41710-0000000c", "__DAY=03") in new stack
    -- Executing [s@sub-record-check:17] Set("SIP/41710-0000000c", "__MONTH=04") in new stack
    -- Executing [s@sub-record-check:18] Set("SIP/41710-0000000c", "__YEAR=2013") in new stack
    -- Executing [s@sub-record-check:19] Set("SIP/41710-0000000c", "__TIMESTR=20130403-143019") in new stack
    -- Executing [s@sub-record-check:20] Set("SIP/41710-0000000c", "__FROMEXTEN=41710") in new stack
    -- Executing [s@sub-record-check:21] Set("SIP/41710-0000000c", "__CALLFILENAME=out-9055611241-41710-20130403-143019-1365013819.18") in new stack
    -- Executing [s@sub-record-check:22] Goto("SIP/41710-0000000c", "out,1") in new stack
    -- Goto (sub-record-check,out,1)
    -- Executing [out@sub-record-check:1] ExecIf("SIP/41710-0000000c", "1?Set(__REC_POLICY_MODE=dontcare)") in new stack
    -- Executing [out@sub-record-check:2] GosubIf("SIP/41710-0000000c", "0?record,1(exten,9055611241,41710)") in new stack
    -- Executing [out@sub-record-check:3] Return("SIP/41710-0000000c", "") in new stack
    -- Executing [9055611241@from-internal:6] Macro("SIP/41710-0000000c", "dialout-trunk,1,9055611241,,off") in new stack
    -- Executing [s@macro-dialout-trunk:1] Set("SIP/41710-0000000c", "DIAL_TRUNK=1") in new stack
    -- Executing [s@macro-dialout-trunk:2] GosubIf("SIP/41710-0000000c", "0?sub-pincheck,s,1()") in new stack
    -- Executing [s@macro-dialout-trunk:3] GotoIf("SIP/41710-0000000c", "0?disabletrunk,1") in new stack
    -- Executing [s@macro-dialout-trunk:4] Set("SIP/41710-0000000c", "DIAL_NUMBER=9055611241") in new stack
    -- Executing [s@macro-dialout-trunk:5] Set("SIP/41710-0000000c", "DIAL_TRUNK_OPTIONS=Ttr") in new stack
    -- Executing [s@macro-dialout-trunk:6] Set("SIP/41710-0000000c", "OUTBOUND_GROUP=OUT_1") in new stack
    -- Executing [s@macro-dialout-trunk:7] GotoIf("SIP/41710-0000000c", "1?nomax") in new stack
    -- Goto (macro-dialout-trunk,s,9)
    -- Executing [s@macro-dialout-trunk:9] GotoIf("SIP/41710-0000000c", "0?skipoutcid") in new stack
    -- Executing [s@macro-dialout-trunk:10] Set("SIP/41710-0000000c", "DIAL_TRUNK_OPTIONS=Tt") in new stack
    -- Executing [s@macro-dialout-trunk:11] Macro("SIP/41710-0000000c", "outbound-callerid,1") in new stack
    -- Executing [s@macro-outbound-callerid:1] ExecIf("SIP/41710-0000000c", "0?Set(CALLERPRES()=)") in new stack
    -- Executing [s@macro-outbound-callerid:2] ExecIf("SIP/41710-0000000c", "0?Set(REALCALLERIDNUM=41710)") in new stack
    -- Executing [s@macro-outbound-callerid:3] GotoIf("SIP/41710-0000000c", "1?normcid") in new stack
    -- Goto (macro-outbound-callerid,s,6)
    -- Executing [s@macro-outbound-callerid:6] Set("SIP/41710-0000000c", "USEROUTCID=") in new stack
    -- Executing [s@macro-outbound-callerid:7] Set("SIP/41710-0000000c", "EMERGENCYCID=") in new stack
    -- Executing [s@macro-outbound-callerid:8] Set("SIP/41710-0000000c", "TRUNKOUTCID="Harte & Lyne" <19055615731>") in new stack
    -- Executing [s@macro-outbound-callerid:9] GotoIf("SIP/41710-0000000c", "1?trunkcid") in new stack
    -- Goto (macro-outbound-callerid,s,14)
    -- Executing [s@macro-outbound-callerid:14] ExecIf("SIP/41710-0000000c", "1?Set(CALLERID(all)="Harte & Lyne" <19055615731>)") in new stack
    -- Executing [s@macro-outbound-callerid:15] ExecIf("SIP/41710-0000000c", "0?Set(CALLERID(all)=)") in new stack
    -- Executing [s@macro-outbound-callerid:16] ExecIf("SIP/41710-0000000c", "1?Set(CALLERID(all)="Harte & Lyne" <19055615731>)") in new stack
    -- Executing [s@macro-outbound-callerid:17] ExecIf("SIP/41710-0000000c", "0?Set(CALLERPRES()=prohib_passed_screen)") in new stack
    -- Executing [s@macro-outbound-callerid:18] Set("SIP/41710-0000000c", "CDR(outbound_cnum)=19055615731") in new stack
    -- Executing [s@macro-outbound-callerid:19] Set("SIP/41710-0000000c", "CDR(outbound_cnam)=Harte & Lyne") in new stack
    -- Executing [s@macro-dialout-trunk:12] GosubIf("SIP/41710-0000000c", "0?sub-flp-1,s,1()") in new stack
    -- Executing [s@macro-dialout-trunk:13] Set("SIP/41710-0000000c", "OUTNUM=9055611241") in new stack
    -- Executing [s@macro-dialout-trunk:14] Set("SIP/41710-0000000c", "custom=DAHDI/1") in new stack
    -- Executing [s@macro-dialout-trunk:15] ExecIf("SIP/41710-0000000c", "0?Set(DIAL_TRUNK_OPTIONS=M(setmusic^default)Tt)") in new stack
    -- Executing [s@macro-dialout-trunk:16] ExecIf("SIP/41710-0000000c", "0?Set(DIAL_TRUNK_OPTIONS=TtM(confirm))") in new stack
    -- Executing [s@macro-dialout-trunk:17] Macro("SIP/41710-0000000c", "dialout-trunk-predial-hook,") in new stack
    -- Executing [s@macro-dialout-trunk-predial-hook:1] MacroExit("SIP/41710-0000000c", "") in new stack
    -- Executing [s@macro-dialout-trunk:18] GotoIf("SIP/41710-0000000c", "0?bypass,1") in new stack
    -- Executing [s@macro-dialout-trunk:19] ExecIf("SIP/41710-0000000c", "1?Set(CONNECTEDLINE(num,i)=9055611241)") in new stack
    -- Executing [s@macro-dialout-trunk:20] ExecIf("SIP/41710-0000000c", "1?Set(CONNECTEDLINE(name,i)=CID:19055615731)") in new stack
    -- Executing [s@macro-dialout-trunk:21] GotoIf("SIP/41710-0000000c", "0?customtrunk") in new stack
    -- Executing [s@macro-dialout-trunk:22] Dial("SIP/41710-0000000c", "DAHDI/1/9055611241,300,Tt") in new stack
[2013-04-03 14:30:19] WARNING[3476][C-0000000e]: app_dial.c:2437 dial_exec_full: Unable to create channel of type 'DAHDI' (cause 17 - User busy)
[2013-04-03 14:30:19] WARNING[3476][C-0000000e]: app_dial.c:2437 dial_exec_full: Unable to create channel of type 'DAHDI' (cause 17 - User busy)
  == Everyone is busy/congested at this time (1:1/0/0)
    -- Executing [s@macro-dialout-trunk:23] NoOp("SIP/41710-0000000c", "Dial failed for some reason with DIALSTATUS = BUSY and HANGUPCAUSE = 17") in new stack
    -- Executing [s@macro-dialout-trunk:24] GotoIf("SIP/41710-0000000c", "0?continue,1:s-BUSY,1") in new stack
    -- Goto (macro-dialout-trunk,s-BUSY,1)
    -- Executing [s-BUSY@macro-dialout-trunk:1] NoOp("SIP/41710-0000000c", "Dial failed due to trunk reporting BUSY - giving up") in new stack
    -- Executing [s-BUSY@macro-dialout-trunk:2] PlayTones("SIP/41710-0000000c", "busy") in new stack
    -- Executing [s-BUSY@macro-dialout-trunk:3] Busy("SIP/41710-0000000c", "20") in new stack
  == Spawn extension (macro-dialout-trunk, s-BUSY, 3) exited non-zero on 'SIP/41710-0000000c' in macro 'dialout-trunk'
  == Spawn extension (from-internal, 9055611241, 6) exited non-zero on 'SIP/41710-0000000c'
    -- Executing [h@from-internal:1] Hangup("SIP/41710-0000000c", "") in new stack
  == Spawn extension (from-internal, h, 1) exited non-zero on 'SIP/41710-0000000c'

bksales · April 3, 2013, 8:12pm

need to see some more of the config to offer an opinion

dicko · April 3, 2013, 8:28pm

from your post:-

– Executing [s@macro-dialout-trunk:22] Dial(“SIP/41710-0000000c”, “DAHDI/1/9055611241,300,Tt”) in new stack
[2013-04-03 14:30:19] WARNING[3476][C-0000000e]: app_dial.c:2437 dial_exec_full: Unable to create channel of type ‘DAHDI’ (cause 17 - User busy

says it all, you are trying to dial 9055611241 on DAHDI/1, but DAHDI/1 apparently is not there, make sure your POTS connection is attached to the first port on your card, look at an inbound call trace to confirm, To debug, start with

dahdi show channels

from the asterisk cli. . .

byrnejb · April 3, 2013, 8:59pm

You are most helpful. The problem was indeed that the POTS line was plugged into FXO 4 and not 1. Moving the line to the correct port resolved the problem. Thank you.