Cisco 7960/7940 Call Forward Problem (CFwdALL)

I’m using FreePBX 2.5.1.0 with some 7960/7940s with the SIP load on them. When the user pushed the CFwdALL button and enters their cell phone it says Forwarded to (the number). But when someone calls their extension Asterisk only calls the forwarded number for about 15 seconds. I’ve tried to change the Ring time in General Setting and the extension to 120 seconds but it still only rings the forwarded number for about 15 seconds.

Does anyone know how to fix this?

Thanks!

Please set your verbose logging to at least 5 and post a copy of the display logs so we have something to look at.

To set the logging go into the asterisk CLI and type: set verbose 5

Then make this happen all the while capturing the output on the screen and post it here please. When you are done you can lower the call logging by typing: set verbose 1

Let me know if you’d like it in pastebin instead. I’ve masked the numbers, FYI.

-- Executing [[email protected]:1] NoOp("SIP/5060-b7d59200", "Received incoming SIP connection from unknown peer to 505XXXXXX") in new stack
-- Executing [[email protected]:2] Set("SIP/5060-b7d59200", "DID=505XXXXXX") in new stack
-- Executing [[email protected]:3] Goto("SIP/5060-b7d59200", "s|1") in new stack
-- Goto (from-sip-external,s,1)
-- Executing [[email protected]:1] GotoIf("SIP/5060-b7d59200", "1?from-trunk|505XXXXXX|1") in new stack
-- Goto (from-trunk,505XXXXXX,1)
-- Executing [[email protected]:1] Set("SIP/5060-b7d59200", "__FROM_DID=505XXXXXX") in new stack
-- Executing [[email protected]:2] ExecIf("SIP/5060-b7d59200", "0 |Set|CALLERID(name)=5059242728") in new stack
-- Executing [[email protected]:3] Set("SIP/5060-b7d59200", "__CALLINGPRES_SV=allowed_not_screened") in new stack
-- Executing [[email protected]:4] SetCallerPres("SIP/5060-b7d59200", "allowed_not_screened") in new stack
-- Executing [[email protected]:5] Goto("SIP/5060-b7d59200", "from-did-direct|300|1") in new stack
-- Goto (from-did-direct,300,1)
-- Executing [[email protected]:1] GotoIf("SIP/5060-b7d59200", "0?ext-local|300|1") in new stack
-- Executing [[email protected]:2] Macro("SIP/5060-b7d59200", "user-callerid|") in new stack
-- Executing [[email protected]:1] Set("SIP/5060-b7d59200", "AMPUSER=5059242728") in new stack
-- Executing [[email protected]:2] GotoIf("SIP/5060-b7d59200", "0?report") in new stack
-- Executing [[email protected]:3] ExecIf("SIP/5060-b7d59200", "1|Set|REALCALLERIDNUM=5059242728") in new stack
-- Executing [[email protected]:4] Set("SIP/5060-b7d59200", "AMPUSER=") in new stack
-- Executing [[email protected]:5] Set("SIP/5060-b7d59200", "AMPUSERCIDNAME=") in new stack
-- Executing [[email protected]:6] GotoIf("SIP/5060-b7d59200", "1?report") in new stack
-- Goto (macro-user-callerid,s,10)
-- Executing [[email protected]:10] GotoIf("SIP/5060-b7d59200", "0?continue") in new stack
-- Executing [[email protected]:11] Set("SIP/5060-b7d59200", "__TTL=64") in new stack
-- Executing [[email protected]:12] GotoIf("SIP/5060-b7d59200", "1?continue") in new stack
-- Goto (macro-user-callerid,s,19)
-- Executing [[email protected]:19] NoOp("SIP/5060-b7d59200", "Using CallerID "Sean Hetherington" <5059242728>") in new stack
-- Executing [[email protected]:3] GotoIf("SIP/5060-b7d59200", "1?skipdb") in new stack
-- Goto (from-did-direct,300,5)
-- Executing [[email protected]:5] Set("SIP/5060-b7d59200", "__NODEST=") in new stack
-- Executing [[email protected]:6] Set("SIP/5060-b7d59200", "__BLKVM_OVERRIDE=BLKVM/300/SIP/5060-b7d59200") in new stack
-- Executing [[email protected]:7] Set("SIP/5060-b7d59200", "__BLKVM_BASE=300") in new stack
-- Executing [[email protected]:8] Set("SIP/5060-b7d59200", "DB(BLKVM/300/SIP/5060-b7d59200)=TRUE") in new stack
-- Executing [[email protected]:9] Set("SIP/5060-b7d59200", "RRNODEST=") in new stack
-- Executing [[email protected]:10] Set("SIP/5060-b7d59200", "__NODEST=300") in new stack
-- Executing [[email protected]:11] Set("SIP/5060-b7d59200", "RecordMethod=Group") in new stack
-- Executing [[email protected]:12] Macro("SIP/5060-b7d59200", "record-enable|300|Group") in new stack
-- Executing [[email protected]:1] GotoIf("SIP/5060-b7d59200", "1?check") in new stack
-- Goto (macro-record-enable,s,4)
-- Executing [[email protected]:4] AGI("SIP/5060-b7d59200", "recordingcheck|20090202-152225|1233613345.500") in new stack
-- Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
-- AGI Script recordingcheck completed, returning 0
-- Executing [[email protected]nable:5] MacroExit("SIP/5060-b7d59200", "") in new stack
-- Executing [[email protected]:13] Set("SIP/5060-b7d59200", "RingGroupMethod=ringallv2") in new stack
-- Executing [[email protected]:14] Set("SIP/5060-b7d59200", "_FMGRP=300") in new stack
-- Executing [[email protected]:15] GotoIf("SIP/5060-b7d59200", "0?doconfirm") in new stack
-- Executing [[email protected]:16] Macro("SIP/5060-b7d59200", "dial|20|tr|300") in new stack
-- Executing [[email protected]:1] GotoIf("SIP/5060-b7d59200", "1?dial") in new stack
-- Goto (macro-dial,s,3)
-- Executing [[email protected]:3] AGI("SIP/5060-b7d59200", "dialparties.agi") in new stack
-- Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi

dialparties.agi: Starting New Dialparties.agi
== Parsing ‘/etc/asterisk/manager.conf’: Found
== Parsing ‘/etc/asterisk/manager_additional.conf’: Found
== Parsing ‘/etc/asterisk/manager_custom.conf’: Found
== Manager ‘admin’ logged on from 127.0.0.1
dialparties.agi: Caller ID name is ‘Sean Hetherington’ number is '5059242728’
dialparties.agi: USE_CONFIRMATION: 'FALSE’
dialparties.agi: RINGGROUP_INDEX: ''
dialparties.agi: Methodology of ring is ‘ringallv2’
– dialparties.agi: Added extension 300 to extension map
> dialparties.agi: got fmgrp_prering: 2, fmgrp_grptime: 20
> dialparties.agi: fmgrp_totalprering: 22
> dialparties.agi: found extension in pre-ring and array
> dialparties.agi: ringallv2 ring times: REALPRERING: 22, PRERING: 2
> dialparties.agi: Extension 300 has call screening off
– dialparties.agi: Extension 300 cf is disabled
– dialparties.agi: Extension 300 do not disturb is disabled
> dialparties.agi: extnum 300 has: cw: 1; hascfb: 0 [] hascfu: 0 []
– dialparties.agi: dbset CALLTRACE/300 to 5059242728
– dialparties.agi: Filtered ARG3: 300
> dialparties.agi: NODEST: 300 adding M(auto-blkvm) to dialopts: trM(auto-blkvm)
> dialparties.agi: NODEST: 300 blkvm enabled macro already in dialopts: trM(auto-blkvm)
== Manager ‘admin’ logged off from 127.0.0.1
– AGI Script dialparties.agi completed, returning 0
– Executing [[email protected]:7] Dial(“SIP/5060-b7d59200”, “SIP/300|22|trM(auto-blkvm)”) in new stack
– Called 300
– Got SIP response 302 “Moved Temporarily” back from 216.31.101.82
– Now forwarding SIP/5060-b7d59200 to ‘Local/[email protected]’ (thanks to SIP/300-092ef8c8)
– Executing [[email protected]:1] Macro(“Local/[email protected],2”, “user-callerid|SKIPTTL|”) in new stack
– Executing [[email protected]:1] Set(“Local/[email protected],2”, “AMPUSER=5059242728”) in new stack
– Executing [[email protected]:2] GotoIf(“Local/[email protected],2”, “1?report”) in new stack
– Goto (macro-user-callerid,s,10)
– Executing [[email protected]:10] GotoIf(“Local/[email protected],2”, “1?continue”) in new stack
– Goto (macro-user-callerid,s,19)
– Executing [[email protected]:19] NoOp(“Local/[email protected],2”, “Using CallerID “Sean Hetherington” <5059242728>”) in new stack
– Executing [[email protected]:2] Set(“Local/[email protected],2”, “_NODEST=”) in new stack
– Executing [[email protected]:3] Macro(“Local/[email protected],2”, “record-enable|5059242728|OUT|”) in new stack
– Executing [[email protected]:1] GotoIf(“Local/[email protected],2”, “1?check”) in new stack
– Goto (macro-record-enable,s,4)
– Executing [[email protected]:4] AGI(“Local/[email protected],2”, “recordingcheck|20090202-152226|1233613346.503”) in new stack
– Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
recordingcheck|20090202-152226|1233613346.503: No AMPUSER db entry for 5059242728. Not recording
– AGI Script recordingcheck completed, returning 0
– Executing [[email protected]:5] MacroExit(“Local/[email protected],2”, “”) in new stack
– Executing [[email protected]:4] Macro(“Local/[email protected],2”, “dialout-trunk|2|NNNNNNN||”) in new stack
– Executing [[email protected]:1] Set(“Local/[email protected],2”, “DIAL_TRUNK=2”) in new stack
– Executing [[email protected]:2] GosubIf(“Local/[email protected],2”, “0?sub-pincheck|s|1”) in new stack
– Executing [[email protected]:3] GotoIf(“Local/[email protected],2”, “0?disabletrunk|1”) in new stack
– Executing [[email protected]:4] Set(“Local/[email protected],2”, “DIAL_NUMBER=NNNNNNN”) in new stack
– Executing [[email protected]:5] Set(“Local/[email protected],2”, “DIAL_TRUNK_OPTIONS=tr”) in new stack
– Executing [[email protected]:6] Set(“Local/[email protected],2”, “OUTBOUND_GROUP=OUT_2”) in new stack
– Executing [[email protected]:7] GotoIf(“Local/[email protected],2”, “1?nomax”) in new stack
– Goto (macro-dialout-trunk,s,9)
– Executing [[email protected]:9] GotoIf(“Local/[email protected],2”, “0?skipoutcid”) in new stack
– Executing [[email protected]:10] Set(“Local/[email protected],2”, “DIAL_TRUNK_OPTIONS=”) in new stack
– Executing [[email protected]:11] Macro(“Local/[email protected],2”, “outbound-callerid|2”) in new stack
– Executing [[email protected]:1] ExecIf(“Local/[email protected],2”, “1|SetCallerPres|allowed_not_screened”) in new stack
– Executing [[email protected]:2] ExecIf(“Local/[email protected],2”, “1|Set|REALCALLERIDNUM=5059242728”) in new stack
– Executing [[email protected]:3] GotoIf(“Local/[email protected],2”, “0?normcid”) in new stack
– Executing [[email protected]:4] Set(“Local/[email protected],2”, “USEROUTCID=5059242728”) in new stack
– Executing [[email protected]:5] GotoIf(“Local/[email protected],2”, “1?bypass”) in new stack
– Goto (macro-outbound-callerid,s,7)
– Executing [[email protected]:7] Set(“Local/[email protected],2”, “EMERGENCYCID=”) in new stack
– Executing [[email protected]:8] Set(“Local/[email protected],2”, “TRUNKOUTCID=“Sonitrol” <5053460750>”) in new stack
– Executing [[email protected]:9] GotoIf(“Local/[email protected],2”, “1?trunkcid”) in new stack
– Goto (macro-outbound-callerid,s,12)
– Executing [[email protected]:12] ExecIf(“Local/[email protected],2”, “1|Set|CALLERID(all)=Sonitrol <5053460750>”) in new stack
– Executing [[email protected]:13] GotoIf(“Local/[email protected],2”, “0?exit”) in new stack
– Executing [[email protected]:14] Set(“Local/[email protected],2”, “CALLERID(all)=5059242728”) in new stack
– Executing [[email protected]:15] ExecIf(“Local/[email protected],2”, “0|SetCallerPres|prohib_passed_screen”) in new stack
– Executing [[email protected]:12] ExecIf(“Local/[email protected],2”, “1|AGI|fixlocalprefix”) in new stack
– Launched AGI Script /var/lib/asterisk/agi-bin/fixlocalprefix
> fixlocalprefix: Using pattern .
== fixlocalprefix: Dialpattern . matched. NNNNNNN -> NNNNNNN
– AGI Script fixlocalprefix completed, returning 0
– Executing [[email protected]:13] Set(“Local/[email protected],2”, “OUTNUM=NNNNNNN”) in new stack
– Executing [[email protected]:14] Set(“Local/[email protected],2”, “custom=SIP/ocip”) in new stack
– Executing [[email protected]:15] ExecIf(“Local/[email protected],2”, “0|Set|DIAL_TRUNK_OPTIONS=M(setmusic^)”) in new stack
– Executing [[email protected]:16] Macro(“Local/[email protected],2”, “dialout-trunk-predial-hook|”) in new stack
– Executing [[email protected]:1] MacroExit(“Local/[email protected],2”, “”) in new stack
– Executing [[email protected]:17] GotoIf(“Local/[email protected],2”, “0?bypass|1”) in new stack
– Executing [[email protected]:18] GotoIf(“Local/[email protected],2”, “0?customtrunk”) in new stack
– Executing [[email protected]:19] Dial(“Local/[email protected],2”, “SIP/ocip/NNNNNNN|300|”) in new stack
– Called ocip/NNNNNNN
– SIP/ocip-b7d01e18 is making progress passing it to Local/[email protected],2
– Local/[email protected],1 is making progress passing it to SIP/5060-b7d59200
– Nobody picked up in 22000 ms
– Executing [[email protected]:8] Set(“SIP/5060-b7d59200”, “DIALSTATUS=NOANSWER”) in new stack
– Executing [[email protected]:9] GosubIf(“SIP/5060-b7d59200”, “0?NOANSWER|1”) in new stack
– Executing [[email protected]:17] Goto(“SIP/5060-b7d59200”, “nextstep”) in new stack
– Goto (from-did-direct,300,19)
– Executing [[email protected]:19] Set(“SIP/5060-b7d59200”, “RingGroupMethod=”) in new stack
– Executing [[email protected]:20] GotoIf(“SIP/5060-b7d59200”, “0?nodest”) in new stack
– Executing [[email protected]:21] Set(“SIP/5060-b7d59200”, “__NODEST=”) in new stack
– Executing [[email protected]:22] DBdel(“SIP/5060-b7d59200”, “BLKVM/300/SIP/5060-b7d59200”) in new stack
– DBdel: family=BLKVM, key=300/SIP/5060-b7d59200
– Executing [[email protected]:23] Goto(“SIP/5060-b7d59200”, “ext-local|vmu300|1”) in new stack
– Goto (ext-local,vmu300,1)
– Executing [[email protected]:1] Macro(“SIP/5060-b7d59200”, “vm|300|NOANSWER|”) in new stack
– Executing [[email protected]:1] Macro(“SIP/5060-b7d59200”, “user-callerid|SKIPTTL”) in new stack
– Executing [[email protected]:1] Set(“SIP/5060-b7d59200”, “AMPUSER=5059242728”) in new stack
– Executing [[email protected]:2] GotoIf(“SIP/5060-b7d59200”, “0?report”) in new stack
– Executing [[email protected]:3] ExecIf(“SIP/5060-b7d59200”, “0|Set|REALCALLERIDNUM=5059242728”) in new stack
– Executing [[email protected]:4] Set(“SIP/5060-b7d59200”, “AMPUSER=”) in new stack
– Executing [[email protected]:5] Set(“SIP/5060-b7d59200”, “AMPUSERCIDNAME=”) in new stack
– Executing [[email protected]:6] GotoIf(“SIP/5060-b7d59200”, “1?report”) in new stack
– Goto (macro-user-callerid,s,10)
– Executing [[email protected]:10] GotoIf(“SIP/5060-b7d59200”, “1?continue”) in new stack
– Goto (macro-user-callerid,s,19)
– Executing [[email protected]:19] NoOp(“SIP/5060-b7d59200”, “Using CallerID “Sean Hetherington” <5059242728>”) in new stack
– Executing [[email protected]:2] Set(“SIP/5060-b7d59200”, “VMGAIN=”"") in new stack
– Executing [[email protected]:3] GotoIf(“SIP/5060-b7d59200”, “1?vmx|1”) in new stack
– Goto (macro-vm,vmx,1)
– Executing [[email protected]:1] GotoIf(“SIP/5060-b7d59200”, “0?s-NOANSWER|1”) in new stack
– Executing [[email protected]:2] Set(“SIP/5060-b7d59200”, “MODE=unavail”) in new stack
– Executing [[email protected]:3] GotoIf(“SIP/5060-b7d59200”, “1?notdirect”) in new stack
– Goto (macro-vm,vmx,5)
– Executing [[email protected]:5] NoOp(“SIP/5060-b7d59200”, "Checking if ext 300 is enabled: ") in new stack
– Executing [[email protected]:6] GotoIf(“SIP/5060-b7d59200”, “1?s-NOANSWER|1”) in new stack
– Goto (macro-vm,s-NOANSWER,1)
– Executing [[email protected]:1] Macro(“SIP/5060-b7d59200”, “get-vmcontext|300”) in new stack
– Executing [[email protected]acro-get-vmcontext:1] Set(“SIP/5060-b7d59200”, “VMCONTEXT=default”) in new stack
– Executing [[email protected]:2] GotoIf(“SIP/5060-b7d59200”, “0?200:300”) in new stack
== Spawn extension (macro-dialout-trunk, s, 19) exited non-zero on ‘Local/[email protected],2’ in macro ‘dialout-trunk’
== Spawn extension (macro-dialout-trunk, s, 19) exited non-zero on ‘Local/[email protected],2’
– Executing [[email protected]:1] Macro(“Local/[email protected],2”, “hangupcall|”) in new stack
– Goto (macro-get-vmcontext,s,300)
– Executing [[email protected]:300] NoOp(“SIP/5060-b7d59200”, “”) in new stack
– Executing [[email protected]:2] VoiceMail(“SIP/5060-b7d59200”, “[email protected]|u”) in new stack
– <SIP/5060-b7d59200> Playing ‘vm-theperson’ (language ‘en’)
– Executing [[email protected]:1] ResetCDR(“Local/[email protected],2”, “w”) in new stack
– Executing [[email protected]:2] NoCDR(“Local/[email protected],2”, “”) in new stack
– Executing [[email protected]:3] GotoIf(“Local/[email protected],2”, “1?skiprg”) in new stack
– Goto (macro-hangupcall,s,6)
– Executing [[email protected]:6] GotoIf(“Local/[email protected],2”, “1?skipblkvm”) in new stack
– Goto (macro-hangupcall,s,9)
– Executing [[email protected]:9] GotoIf(“Local/[email protected],2”, “1?theend”) in new stack
– Goto (macro-hangupcall,s,11)
– Executing [[email protected]:11] Hangup(“Local/[email protected],2”, “”) in new stack
== Spawn extension (macro-hangupcall, s, 11) exited non-zero on ‘Local/[email protected],2’ in macro ‘hangupcall’
== Spawn extension (macro-hangupcall, s, 11) exited non-zero on ‘Local/[email protected],2’
– <SIP/5060-b7d59200> Playing ‘digits/3’ (language ‘en’)
== Spawn extension (macro-vm, s-NOANSWER, 2) exited non-zero on ‘SIP/5060-b7d59200’ in macro ‘vm’
== Spawn extension (macro-vm, s-NOANSWER, 2) exited non-zero on ‘SIP/5060-b7d59200’
== Spawn extension (macro-dialout-trunk, s, 19) exited non-zero on ‘SIP/9800-b7d308b0’ in macro ‘dialout-trunk’
== Spawn extension (macro-dialout-trunk, s, 19) exited non-zero on ‘SIP/9800-b7d308b0’
– Executing [[email protected]:1] Macro(“SIP/9800-b7d308b0”, “hangupcall|”) in new stack
– Executing [[email protected]:1] ResetCDR(“SIP/9800-b7d308b0”, “w”) in new stack
– Executing [[email protected]:2] NoCDR(“SIP/9800-b7d308b0”, “”) in new stack
– Executing [[email protected]:3] GotoIf(“SIP/9800-b7d308b0”, “1?skiprg”) in new stack
– Goto (macro-hangupcall,s,6)
– Executing [[email protected]:6] GotoIf(“SIP/9800-b7d308b0”, “1?skipblkvm”) in new stack
– Goto (macro-hangupcall,s,9)
– Executing [[email protected]:9] GotoIf(“SIP/9800-b7d308b0”, “1?theend”) in new stack
– Goto (macro-hangupcall,s,11)
– Executing [[email protected]:11] Hangup(“SIP/9800-b7d308b0”, “”) in new stack
== Spawn extension (macro-hangupcall, s, 11) exited non-zero on ‘SIP/9800-b7d308b0’ in macro ‘hangupcall’
== Spawn extension (macro-hangupcall, s, 11) exited non-zero on ‘SIP/9800-b7d308b0’

it looks like 22 seconds not 15…

See:
– Called ocip/NNNNNNN
– SIP/ocip-b7d01e18 is making progress passing it to Local/[email protected],2
– Local/[email protected],1 is making progress passing it to SIP/5060-b7d59200
– Nobody picked up in 22000 ms

It looks like your Sip provider might be dropping it in 22 seconds. open your extensions_additional.conf file and search for macro-dialout-trunk, then locate the 19th line. It should look like:
exten => s,n,Dial(${OUT_${DIAL_TRUNK}}/${OUTNUM},300,${DIAL_TRUNK_OPTIONS})

That is the default line so assuming you’ve not changed the 300 down to 22 it should still be ringing based on what asterisk is telling it to do when it dials. So how ever your Sip trunk and/or provider are setup that is limiting it.