ftocc

Can't always pick-up/answer call

MillsapsPE
Posts: 313
Member Since:
2006-06-09

Background/Setup
Did a new/fresh install w/ 2.6.0.7 and quickly upgraded to 2.6.1 beta due to problems with the GUI after installing HUD.

This system is operating with Polycom phones (301, 430, 501, 601) and one old Sipura 842 phone. Polycom's running 3.0.1-2. The 842 is RARELY used.

All incoming calls are coming through Sangoma A200d card. Calls first go through a Time Condition, then to a Ring Group (461). Ring Group 461 is a RINGALL group with all of the extensions entered on the extension list.

The Problem:
When a call comes in, all the phones ring as they should. But, no one can answer the call. As established in the Ring Group 461, the calls rolls over to an IVR after 20 seconds.

This does not happen all the time, only occassionally. I have not been able to figure out a pattern yet.

A new twist today. Person answered call (coming through ring group). Person transferred call (not sure if blind or attended) and person B could not answer/pick-up ringing phone.

I don't really know why, but I'm starting to think it is the a problem with the phone. Can someone point some additional troubleshooting tips? I can't sit and watch the output on the screen all day waiting for it to happen. Though I was lucky enough to catch it once.

Below is output from an incoming call on ZAP 2-1. A call was already in progress on ZAP 1-1. It appears the system thinks the extensions are busy (see bold text below). Anyone know why this happens or how to correct it? This has been happening since day 1 of this install.

*****************************************************
-- Starting simple switch on 'Zap/2-1'
-- Executing [s@from-zaptel:1] NoOp("Zap/2-1", "Entering from-zaptel with DID == ") in new stack
-- Executing [s@from-zaptel:2] Ringing("Zap/2-1", "") in new stack
-- Executing [s@from-zaptel:3] Set("Zap/2-1", "DID=s") in new stack
-- Executing [s@from-zaptel:4] NoOp("Zap/2-1", "DID is now s") in new stack
-- Executing [s@from-zaptel:5] GotoIf("Zap/2-1", "1?zapok:notzap") in new stack
-- Goto (from-zaptel,s,8)
-- Executing [s@from-zaptel:8] NoOp("Zap/2-1", "Is a Zaptel Channel") in new stack
-- Executing [s@from-zaptel:9] Set("Zap/2-1", "CHAN=2-1") in new stack
-- Executing [s@from-zaptel:10] Set("Zap/2-1", "CHAN=2") in new stack
-- Executing [s@from-zaptel:11] Macro("Zap/2-1", "from-zaptel-2|s|1") in new stack
-- Executing [s@from-zaptel:12] NoOp("Zap/2-1", "Returned from Macro from-zaptel-2") in new stack
-- Executing [s@from-zaptel:13] Goto("Zap/2-1", "from-pstn|s|1") in new stack
-- Goto (from-pstn,s,1)
-- Executing [s@from-pstn:1] Set("Zap/2-1", "__FROM_DID=s") in new stack
-- Executing [s@from-pstn:2] Gosub("Zap/2-1", "app-blacklist-check|s|1") in new stack
-- Executing [s@app-blacklist-check:1] LookupBlacklist("Zap/2-1", "") in new stack
-- Executing [s@app-blacklist-check:2] GotoIf("Zap/2-1", "0?blacklisted") in new stack
-- Executing [s@app-blacklist-check:3] Return("Zap/2-1", "") in new stack
-- Executing [s@from-pstn:3] GotoIf("Zap/2-1", "0 ?cidok") in new stack
-- Executing [s@from-pstn:4] Set("Zap/2-1", "CALLERID(name)=8065551212") in new stack
-- Executing [s@from-pstn:5] NoOp("Zap/2-1", "CallerID is "8065551212" <8065551212>") in new stack
-- Executing [s@from-pstn:6] Goto("Zap/2-1", "timeconditions|1|1") in new stack
-- Goto (timeconditions,1,1)
-- Executing [1@timeconditions:1] GotoIfTime("Zap/2-1", "08:02-17:00|mon-fri|*|*?ext-group|461|1") in new stack
-- Goto (ext-group,461,1)
-- Executing [461@ext-group:1] Macro("Zap/2-1", "user-callerid|") in new stack
-- Executing [s@macro-user-callerid:1] NoOp("Zap/2-1", "user-callerid: 8065551212 8065551212") in new stack
-- Executing [s@macro-user-callerid:2] Set("Zap/2-1", "AMPUSER=8065551212") in new stack
-- Executing [s@macro-user-callerid:3] GotoIf("Zap/2-1", "0?report") in new stack
-- Executing [s@macro-user-callerid:4] ExecIf("Zap/2-1", "1|Set|REALCALLERIDNUM=8065551212") in new stack
-- Executing [s@macro-user-callerid:5] NoOp("Zap/2-1", "REALCALLERIDNUM is 8065551212") in new stack
-- Executing [s@macro-user-callerid:6] Set("Zap/2-1", "AMPUSER=") in new stack
-- Executing [s@macro-user-callerid:7] Set("Zap/2-1", "AMPUSERCIDNAME=") in new stack
-- Executing [s@macro-user-callerid:8] GotoIf("Zap/2-1", "1?report") in new stack
-- Goto (macro-user-callerid,s,13)
-- Executing [s@macro-user-callerid:13] NoOp("Zap/2-1", "TTL: ARG1: ") in new stack
-- Executing [s@macro-user-callerid:14] GotoIf("Zap/2-1", "0?continue") in new stack
-- Executing [s@macro-user-callerid:15] Set("Zap/2-1", "__TTL=64") in new stack
-- Executing [s@macro-user-callerid:16] GotoIf("Zap/2-1", "1?continue") in new stack
-- Goto (macro-user-callerid,s,23)
-- Executing [s@macro-user-callerid:23] NoOp("Zap/2-1", "Using CallerID "8065551212" <8065551212>") in new stack
-- Executing [461@ext-group:2] GotoIf("Zap/2-1", "1?skipdb") in new stack
-- Goto (ext-group,461,4)
-- Executing [461@ext-group:4] Set("Zap/2-1", "__NODEST=") in new stack
-- Executing [461@ext-group:5] Set("Zap/2-1", "__BLKVM_OVERRIDE=BLKVM/461/Zap/2-1") in new stack
-- Executing [461@ext-group:6] Set("Zap/2-1", "__BLKVM_BASE=461") in new stack
-- Executing [461@ext-group:7] Set("Zap/2-1", "DB(BLKVM/461/Zap/2-1)=TRUE") in new stack
-- Executing [461@ext-group:8] Set("Zap/2-1", "RRNODEST=") in new stack
-- Executing [461@ext-group:9] Set("Zap/2-1", "__NODEST=461") in new stack
-- Executing [461@ext-group:10] Set("Zap/2-1", "RecordMethod=Group") in new stack
-- Executing [461@ext-group:11] Macro("Zap/2-1", "record-enable|400-401-402-403-404-405-408|Group") in new stack
-- Executing [s@macro-record-enable:1] GotoIf("Zap/2-1", "0?2:4") in new stack
-- Goto (macro-record-enable,s,4)
-- Executing [s@macro-record-enable:4] AGI("Zap/2-1", "recordingcheck|20080523-151244|1211573563.3184") in new stack
-- Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
-- AGI Script recordingcheck completed, returning 0
-- Executing [s@macro-record-enable:5] NoOp("Zap/2-1", "No recording needed") in new stack
-- Executing [461@ext-group:12] Set("Zap/2-1", "RingGroupMethod=ringall") in new stack
-- Executing [461@ext-group:13] Macro("Zap/2-1", "dial|20|trW|400-401-402-403-404-405-408") in new stack
-- Executing [s@macro-dial:1] GotoIf("Zap/2-1", "1?dial") in new stack
-- Goto (macro-dial,s,3)
-- Executing [s@macro-dial:3] AGI("Zap/2-1", "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_custom.conf': Found
== Manager 'admin' logged on from 127.0.0.1
dialparties.agi: Caller ID name is '8065551212' number is '8065551212'
dialparties.agi: USE_CONFIRMATION: 'FALSE'
dialparties.agi: RINGGROUP_INDEX: ''
dialparties.agi: Methodology of ring is 'ringall'
-- dialparties.agi: Added extension 400 to extension map
-- dialparties.agi: Added extension 401 to extension map
-- dialparties.agi: Added extension 402 to extension map
-- dialparties.agi: Added extension 403 to extension map
-- dialparties.agi: Added extension 404 to extension map
-- dialparties.agi: Added extension 405 to extension map
-- dialparties.agi: Added extension 408 to extension map
-- dialparties.agi: Extension 400 cf is disabled
-- dialparties.agi: Extension 401 cf is disabled
-- dialparties.agi: Extension 402 cf is disabled
-- dialparties.agi: Extension 403 cf is disabled
-- dialparties.agi: Extension 404 cf is disabled
-- dialparties.agi: Extension 405 cf is disabled
-- dialparties.agi: Extension 408 cf is disabled
-- dialparties.agi: Extension 400 do not disturb is disabled
-- dialparties.agi: Extension 401 do not disturb is disabled
-- dialparties.agi: Extension 402 do not disturb is disabled
-- dialparties.agi: Extension 403 do not disturb is disabled
-- dialparties.agi: Extension 404 do not disturb is disabled
-- dialparties.agi: Extension 405 do not disturb is disabled
-- dialparties.agi: Extension 408 do not disturb is disabled
> dialparties.agi: extnum 400 has: cw: 1; hascfb: 0 [] hascfu: 0 []
-- dialparties.agi: dbset CALLTRACE/400 to 8065551212
> dialparties.agi: extnum 401 has: cw: 1; hascfb: 0 [] hascfu: 0 []
-- dialparties.agi: dbset CALLTRACE/401 to 8065551212
> dialparties.agi: extnum 402 has: cw: 1; hascfb: 0 [] hascfu: 0 []
-- dialparties.agi: dbset CALLTRACE/402 to 8065551212
> dialparties.agi: extnum 403 has: cw: 1; hascfb: 0 [] hascfu: 0 []
-- dialparties.agi: dbset CALLTRACE/403 to 8065551212
> dialparties.agi: extnum 404 has: cw: 1; hascfb: 0 [] hascfu: 0 []
-- dialparties.agi: dbset CALLTRACE/404 to 8065551212
> dialparties.agi: extnum 405 has: cw: 1; hascfb: 0 [] hascfu: 0 []
-- dialparties.agi: dbset CALLTRACE/405 to 8065551212
> dialparties.agi: extnum 408 has: cw: 1; hascfb: 0 [] hascfu: 0 []
-- dialparties.agi: dbset CALLTRACE/408 to 8065551212
-- dialparties.agi: Filtered ARG3: 400-401-402-403-404-405-408
> dialparties.agi: NODEST: 461 adding M(auto-blkvm) to dialopts: trWM(auto-blkvm)
> dialparties.agi: NODEST: 461 blkvm enabled macro already in dialopts: trWM(auto-blkvm)
== Manager 'admin' logged off from 127.0.0.1
-- AGI Script dialparties.agi completed, returning 0
-- Executing [s@macro-dial:7] Dial("Zap/2-1", "SIP/400&SIP/401&SIP/402&SIP/403&SIP/404&SIP/405&SIP/408|20|trWM(auto-blkvm)") in new stack
-- Called 400
-- Called 401
-- Called 402
-- Called 403
-- Called 404
-- Called 405
-- Called 408
Extension Changed 401[ext-local] new state InUse&Ringing for Notify User 400 <--- EXTENSION 400 WAS ALREADY ON A CALL
Extension Changed 402[ext-local] new state Ringing for Notify User 400
Extension Changed 403[ext-local] new state Ringing for Notify User 400
Extension Changed 404[ext-local] new state Ringing for Notify User 400
Extension Changed 405[ext-local] new state Ringing for Notify User 400
Extension Changed 408[ext-local] new state Ringing for Notify User 400
Extension Changed 401[ext-local] new state Ringing for Notify User 400 (queued)
-- SIP/400-0a1fbe58 is circuit-busy
-- SIP/401-0a21c298 is circuit-busy
-- SIP/402-0a262c98 is circuit-busy

-- Incoming call: Got SIP response 500 "Internal Server Error" back from 192.168.2.59 <-- EXTENSION 400
Extension Changed 401[ext-local] new state Idle for Notify User 400 (queued)
-- SIP/403-0a266c10 is circuit-busy
-- SIP/404-0a1ea948 is circuit-busy
-- SIP/405-0a1ee8c0 is circuit-busy
-- SIP/408-0a1d8d50 is circuit-busy
== Everyone is busy/congested at this time (7:0/7/0)

-- Executing [s@macro-dial:8] Set("Zap/2-1", "DIALSTATUS=CONGESTION") in new stack
-- Executing [461@ext-group:14] Set("Zap/2-1", "RingGroupMethod=") in new stack
-- Executing [461@ext-group:15] GotoIf("Zap/2-1", "0?nodest") in new stack
-- Executing [461@ext-group:16] Set("Zap/2-1", "__NODEST=") in new stack
-- Executing [461@ext-group:17] DBdel("Zap/2-1", "BLKVM/461/Zap/2-1") in new stack
-- DBdel: family=BLKVM, key=461/Zap/2-1
-- Executing [461@ext-group:18] Goto("Zap/2-1", "ivr-3|s|1") in new stack
-- Goto (ivr-3,s,1)
-- Executing [s@ivr-3:1] Set("Zap/2-1", "LOOPCOUNT=0") in new stack
-- Executing [s@ivr-3:2] Set("Zap/2-1", "__DIR-CONTEXT=default") in new stack
-- Executing [s@ivr-3:3] Set("Zap/2-1", "_IVR_CONTEXT_ivr-3=") in new stack
-- Executing [s@ivr-3:4] Set("Zap/2-1", "_IVR_CONTEXT=ivr-3") in new stack
-- Executing [s@ivr-3:5] GotoIf("Zap/2-1", "0?begin") in new stack
-- Executing [s@ivr-3:6] Answer("Zap/2-1", "") in new stack
-- Executing [s@ivr-3:7] Wait("Zap/2-1", "1") in new stack
-- Executing [s@ivr-3:8] Set("Zap/2-1", "TIMEOUT(digit)=3") in new stack
-- Digit timeout set to 3
-- Executing [s@ivr-3:9] Set("Zap/2-1", "TIMEOUT(response)=10") in new stack
-- Response timeout set to 10
-- Executing [s@ivr-3:10] BackGround("Zap/2-1", "custom/Unavailable") in new stack
-- Playing 'custom/Unavailable' (language 'en')
Extension Changed 404[ext-local] new state Idle for Notify User 400

THE REST IS FROM THE UNAVAILABLE IVR AND OTHER CALLS