ATA not ringing the phone

Hi all.

I have this random problem that just confuse the heck out of me. My incoming sometime ring my ATA box but most of the time just throw the caller into voicemail. Here is my log.

Calling to: 206-555-1212
Calling from: 206-555-1234

Freepbx: 2.11
Asterisk 11.
OS: Centos 6.4 64 Bit
ATA: Handytone 286

I’m speculating this has something to do with the setting in the ATA but I’m not quite sure. Is there anything else I need to provide to help me debug this issue? Please help? Many thanks.

Connected to Asterisk 11.4.0 currently running on myfreepbx (pid = 23168) == Using SIP RTP TOS bits 184 == Using SIP RTP CoS mark 5 -- Executing [[email protected]:1] Set("SIP/2065551212_VOIPO-00000000", "__FROM_DID=2065551212") in new stack -- Executing [[email protected]:2] Gosub("SIP/2065551212_VOIPO-00000000", "app-blacklist-check,s,1()") in new stack -- Executing [[email protected]:1] GotoIf("SIP/2065551212_VOIPO-00000000", "0?blacklisted") in new stack -- Executing [[email protected]:2] Set("SIP/2065551212_VOIPO-00000000", "CALLED_BLACKLIST=1") in new stack -- Executing [[email protected]:3] Return("SIP/2065551212_VOIPO-00000000", "") in new stack -- Executing [[email protected]:3] Set("SIP/2065551212_VOIPO-00000000", "CIDSFSCHEME=QUxMfEFMTA==") in new stack -- Executing [[email protected]:4] AGI("SIP/2065551212_VOIPO-00000000", "/var/www/html/admin/modules/superfecta/agi/superfecta.agi") in new stack -- Launched AGI Script /var/www/html/admin/modules/superfecta/agi/superfecta.agi /var/www/html/admin/modules/superfecta/agi/superfecta.agi: CID Superfecta is Answering the Channel /var/www/html/admin/modules/superfecta/agi/superfecta.agi: CID Superfecta: Scheme is ALL /var/www/html/admin/modules/superfecta/agi/superfecta.agi: CID Superfecta: The DID passed from Asterisk is: 2065551212 /var/www/html/admin/modules/superfecta/agi/superfecta.agi: CID Superfecta: The number passed from Asterisk is: 2065551234 /var/www/html/admin/modules/superfecta/agi/superfecta.agi: CID Superfecta: The CID name passed from Asterisk is: SEATTLE WA /var/www/html/admin/modules/superfecta/agi/superfecta.agi: CID Superfecta: Executing Scheme.. /var/www/html/admin/modules/superfecta/agi/superfecta.agi: CID Superfecta: CID Determined to be: 'SEATTLE WA' /var/www/html/admin/modules/superfecta/agi/superfecta.agi: CID Superfecta: Attempting to set lookupcid /var/www/html/admin/modules/superfecta/agi/superfecta.agi: CID Superfecta: Success! -- AGI Script /var/www/html/admin/modules/superfecta/agi/superfecta.agi completed, returning 0 -- Executing [[email protected]:5] Set("SIP/2065551212_VOIPO-00000000", "CALLERID(name)=SEATTLE WA") in new stack -- Executing [[email protected]:6] Set("SIP/2065551212_VOIPO-00000000", "CDR(did)=2065551212") in new stack -- Executing [[email protected]:7] ExecIf("SIP/2065551212_VOIPO-00000000", "0 ?Set(CALLERID(name)=2065551234)") in new stack [2013-09-24 16:09:56] WARNING[23229][C-00000000]: func_callerid.c:905 callerpres_read: CALLERPRES is deprecated. Use CALLERID(name-pres) or CALLERID(num-pres) instead. -- Executing [[email protected]:8] Set("SIP/2065551212_VOIPO-00000000", "__CALLINGPRES_SV=allowed_not_screened") in new stack -- Executing [[email protected]:9] Set("SIP/2065551212_VOIPO-00000000", "CALLERPRES()=allowed_not_screened") in new stack -- Executing [[email protected]:10] Goto("SIP/2065551212_VOIPO-00000000", "from-did-direct,8881,1") in new stack -- Goto (from-did-direct,8881,1) -- Executing [[email protected]:1] Set("SIP/2065551212_VOIPO-00000000", "__RINGTIMER=28") in new stack -- Executing [[email protected]:2] Macro("SIP/2065551212_VOIPO-00000000", "exten-vm,8881,8881,0,0,0") in new stack -- Executing [[email protected]:1] Macro("SIP/2065551212_VOIPO-00000000", "user-callerid,") in new stack -- Executing [[email protected]:1] Set("SIP/2065551212_VOIPO-00000000", "TOUCH_MONITOR=1380064195.0") in new stack -- Executing [[email protected]:2] Set("SIP/2065551212_VOIPO-00000000", "AMPUSER=2065551234") in new stack -- Executing [[email protected]:3] GotoIf("SIP/2065551212_VOIPO-00000000", "0?report") in new stack -- Executing [[email protected]:4] ExecIf("SIP/2065551212_VOIPO-00000000", "1?Set(REALCALLERIDNUM=2065551234)") in new stack -- Executing [[email protected]:5] Set("SIP/2065551212_VOIPO-00000000", "AMPUSER=") in new stack -- Executing [[email protected]:6] Set("SIP/2065551212_VOIPO-00000000", "AMPUSERCIDNAME=") in new stack -- Executing [[email protected]:7] GotoIf("SIP/2065551212_VOIPO-00000000", "1?report") in new stack -- Goto (macro-user-callerid,s,15) -- Executing [[email protected]:15] GotoIf("SIP/2065551212_VOIPO-00000000", "0?continue") in new stack -- Executing [[email protected]:16] Set("SIP/2065551212_VOIPO-00000000", "__TTL=64") in new stack -- Executing [[email protected]:17] GotoIf("SIP/2065551212_VOIPO-00000000", "1?continue") in new stack -- Goto (macro-user-callerid,s,28) -- Executing [[email protected]:28] Set("SIP/2065551212_VOIPO-00000000", "CALLERID(number)=2065551234") in new stack -- Executing [[email protected]:29] Set("SIP/2065551212_VOIPO-00000000", "CALLERID(name)=SEATTLE WA") in new stack -- Executing [[email protected]:30] Set("SIP/2065551212_VOIPO-00000000", "CDR(cnum)=2065551234") in new stack -- Executing [[email protected]:31] Set("SIP/2065551212_VOIPO-00000000", "CDR(cnam)=SEATTLE WA") in new stack -- Executing [[email protected]:32] Set("SIP/2065551212_VOIPO-00000000", "CHANNEL(language)=en") in new stack -- Executing [[email protected]:2] Set("SIP/2065551212_VOIPO-00000000", "RingGroupMethod=none") in new stack -- Executing [[email protected]:3] Set("SIP/2065551212_VOIPO-00000000", "__EXTTOCALL=8881") in new stack -- Executing [[email protected]:4] Set("SIP/2065551212_VOIPO-00000000", "__PICKUPMARK=8881") in new stack -- Executing [[email protected]:5] Set("SIP/2065551212_VOIPO-00000000", "RT=28") in new stack -- Executing [[email protected]:6] ExecIf("SIP/2065551212_VOIPO-00000000", "0?Macro(vm,8881,DIRECTDIAL,)") in new stack -- Executing [[email protected]:7] ExecIf("SIP/2065551212_VOIPO-00000000", "0?MacroExit()") in new stack -- Executing [[email protected]:8] Gosub("SIP/2065551212_VOIPO-00000000", "sub-record-check,s,1(exten,8881,)") in new stack -- Executing [[email protected]:1] Set("SIP/2065551212_VOIPO-00000000", "REC_POLICY_MODE_SAVE=") in new stack -- Executing [[email protected]:2] GotoIf("SIP/2065551212_VOIPO-00000000", "1?check") in new stack -- Goto (sub-record-check,s,7) -- Executing [[email protected]:7] Set("SIP/2065551212_VOIPO-00000000", "__MON_FMT=wav") in new stack -- Executing [[email protected]:8] GotoIf("SIP/2065551212_VOIPO-00000000", "1?next") in new stack -- Goto (sub-record-check,s,11) -- Executing [[email protected]:11] ExecIf("SIP/2065551212_VOIPO-00000000", "0?Return()") in new stack -- Executing [[email protected]:12] ExecIf("SIP/2065551212_VOIPO-00000000", "0?Set(__REC_POLICY_MODE=)") in new stack -- Executing [[email protected]:13] GotoIf("SIP/2065551212_VOIPO-00000000", "0?exten,1") in new stack -- Executing [[email protected]:14] Set("SIP/2065551212_VOIPO-00000000", "__REC_STATUS=INITIALIZED") in new stack -- Executing [[email protected]:15] Set("SIP/2065551212_VOIPO-00000000", "NOW=1380064196") in new stack -- Executing [[email protected]:16] Set("SIP/2065551212_VOIPO-00000000", "__DAY=24") in new stack -- Executing [[email protected]:17] Set("SIP/2065551212_VOIPO-00000000", "__MONTH=09") in new stack -- Executing [[email protected]:18] Set("SIP/2065551212_VOIPO-00000000", "__YEAR=2013") in new stack -- Executing [[email protected]:19] Set("SIP/2065551212_VOIPO-00000000", "__TIMESTR=20130924-160956") in new stack -- Executing [[email protected]:20] Set("SIP/2065551212_VOIPO-00000000", "__FROMEXTEN=2065551234") in new stack -- Executing [[email protected]:21] Set("SIP/2065551212_VOIPO-00000000", "__CALLFILENAME=exten-8881-2065551234-20130924-160956-1380064195.0") in new stack -- Executing [[email protected]:22] Goto("SIP/2065551212_VOIPO-00000000", "exten,1") in new stack -- Goto (sub-record-check,exten,1) -- Executing [[email protected]:1] GotoIf("SIP/2065551212_VOIPO-00000000", "0?callee") in new stack -- Executing [[email protected]:2] Set("SIP/2065551212_VOIPO-00000000", "__REC_POLICY_MODE=dontcare") in new stack -- Executing [[email protected]:3] GotoIf("SIP/2065551212_VOIPO-00000000", "1?caller") in new stack -- Goto (sub-record-check,exten,10) -- Executing [[email protected]:10] Set("SIP/2065551212_VOIPO-00000000", "__REC_POLICY_MODE=") in new stack -- Executing [[email protected]:11] GosubIf("SIP/2065551212_VOIPO-00000000", "0?record,1(exten,8881,2065551234)") in new stack -- Executing [[email protected]:12] Return("SIP/2065551212_VOIPO-00000000", "") in new stack -- Executing [[email protected]:9] GotoIf("SIP/2065551212_VOIPO-00000000", "1?macrodial") in new stack -- Goto (macro-exten-vm,s,15) -- Executing [[email protected]:15] GosubIf("SIP/2065551212_VOIPO-00000000", "0?clrheader,1()") in new stack -- Executing [[email protected]:16] Macro("SIP/2065551212_VOIPO-00000000", "dial-one,28,Ttr,8881") in new stack -- Executing [[email protected]:1] Set("SIP/2065551212_VOIPO-00000000", "DEXTEN=8881") in new stack -- Executing [[email protected]:2] Set("SIP/2065551212_VOIPO-00000000", "DIALSTATUS_CW=") in new stack -- Executing [[email protected]:3] GosubIf("SIP/2065551212_VOIPO-00000000", "0?screen,1()") in new stack -- Executing [[email protected]:4] GosubIf("SIP/2065551212_VOIPO-00000000", "0?cf,1()") in new stack -- Executing [[email protected]:5] GotoIf("SIP/2065551212_VOIPO-00000000", "1?skip1") in new stack -- Goto (macro-dial-one,s,8) -- Executing [[email protected]:8] GotoIf("SIP/2065551212_VOIPO-00000000", "0?nodial") in new stack -- Executing [[email protected]:9] GotoIf("SIP/2065551212_VOIPO-00000000", "0?continue") in new stack -- Executing [[email protected]:10] Set("SIP/2065551212_VOIPO-00000000", "EXTHASCW=ENABLED") in new stack -- Executing [[email protected]:11] GotoIf("SIP/2065551212_VOIPO-00000000", "0?next1:cwinusebusy") in new stack -- Goto (macro-dial-one,s,23) -- Executing [[email protected]:23] GotoIf("SIP/2065551212_VOIPO-00000000", "1?next3:continue") in new stack -- Goto (macro-dial-one,s,24) -- Executing [[email protected]:24] ExecIf("SIP/2065551212_VOIPO-00000000", "0?Set(DIALSTATUS_CW=BUSY)") in new stack -- Executing [[email protected]:25] GotoIf("SIP/2065551212_VOIPO-00000000", "0?nodial") in new stack -- Executing [[email protected]:26] GosubIf("SIP/2065551212_VOIPO-00000000", "1?dstring,1():dlocal,1()") in new stack -- Executing [[email protected]:1] Set("SIP/2065551212_VOIPO-00000000", "DSTRING=") in new stack -- Executing [[email protected]:2] Set("SIP/2065551212_VOIPO-00000000", "DEVICES=8881") in new stack -- Executing [[email protected]:3] ExecIf("SIP/2065551212_VOIPO-00000000", "0?Return()") in new stack -- Executing [[email protected]:4] ExecIf("SIP/2065551212_VOIPO-00000000", "0?Set(DEVICES=881)") in new stack -- Executing [[email protected]:5] Set("SIP/2065551212_VOIPO-00000000", "LOOPCNT=1") in new stack -- Executing [[email protected]:6] Set("SIP/2065551212_VOIPO-00000000", "ITER=1") in new stack -- Executing [[email protected]:7] Set("SIP/2065551212_VOIPO-00000000", "THISDIAL=SIP/8881") in new stack -- Executing [[email protected]:8] GosubIf("SIP/2065551212_VOIPO-00000000", "1?zap2dahdi,1()") in new stack -- Executing [[email protected]:1] ExecIf("SIP/2065551212_VOIPO-00000000", "0?Return()") in new stack -- Executing [[email protected]:2] Set("SIP/2065551212_VOIPO-00000000", "NEWDIAL=") in new stack -- Executing [[email protected]:3] Set("SIP/2065551212_VOIPO-00000000", "LOOPCNT2=1") in new stack -- Executing [[email protected]:4] Set("SIP/2065551212_VOIPO-00000000", "ITER2=1") in new stack -- Executing [[email protected]:5] Set("SIP/2065551212_VOIPO-00000000", "THISPART2=SIP/8881") in new stack -- Executing [[email protected]:6] ExecIf("SIP/2065551212_VOIPO-00000000", "0?Set(THISPART2=DAHDI/8881)") in new stack -- Executing [[email protected]:7] Set("SIP/2065551212_VOIPO-00000000", "NEWDIAL=SIP/8881&") in new stack -- Executing [[email protected]:8] Set("SIP/2065551212_VOIPO-00000000", "ITER2=2") in new stack -- Executing [[email protected]:9] GotoIf("SIP/2065551212_VOIPO-00000000", "0?begin2") in new stack -- Executing [[email protected]:10] Set("SIP/2065551212_VOIPO-00000000", "THISDIAL=SIP/8881") in new stack -- Executing [[email protected]:11] Return("SIP/2065551212_VOIPO-00000000", "") in new stack -- Executing [[email protected]:9] Set("SIP/2065551212_VOIPO-00000000", "DSTRING=SIP/8881&") in new stack -- Executing [[email protected]:10] Set("SIP/2065551212_VOIPO-00000000", "ITER=2") in new stack -- Executing [[email protected]:11] GotoIf("SIP/2065551212_VOIPO-00000000", "0?begin") in new stack -- Executing [[email protected]:12] Set("SIP/2065551212_VOIPO-00000000", "DSTRING=SIP/8881") in new stack -- Executing [[email protected]:13] Return("SIP/2065551212_VOIPO-00000000", "") in new stack -- Executing [[email protected]:27] GotoIf("SIP/2065551212_VOIPO-00000000", "0?nodial") in new stack -- Executing [[email protected]:28] GotoIf("SIP/2065551212_VOIPO-00000000", "0?skiptrace") in new stack -- Executing [[email protected]:29] GosubIf("SIP/2065551212_VOIPO-00000000", "1?ctset,1():ctclear,1()") in new stack -- Executing [[email protected]:1] Set("SIP/2065551212_VOIPO-00000000", "DB(CALLTRACE/8881)=2065551234") in new stack -- Executing [[email protected]:2] Return("SIP/2065551212_VOIPO-00000000", "") in new stack -- Executing [[email protected]:30] Set("SIP/2065551212_VOIPO-00000000", "D_OPTIONS=Ttr") in new stack -- Executing [[email protected]:31] ExecIf("SIP/2065551212_VOIPO-00000000", "0?SIPAddHeader(Alert-Info: )") in new stack -- Executing [[email protected]:32] ExecIf("SIP/2065551212_VOIPO-00000000", "0?SIPAddHeader()") in new stack -- Executing [[email protected]:33] ExecIf("SIP/2065551212_VOIPO-00000000", "0?Set(CHANNEL(musicclass)=)") in new stack -- Executing [[email protected]:34] GosubIf("SIP/2065551212_VOIPO-00000000", "0?qwait,1()") in new stack -- Executing [[email protected]:35] Set("SIP/2065551212_VOIPO-00000000", "__CWIGNORE=") in new stack -- Executing [[email protected]:36] Set("SIP/2065551212_VOIPO-00000000", "__KEEPCID=TRUE") in new stack -- Executing [[email protected]:37] GotoIf("SIP/2065551212_VOIPO-00000000", "0?usegoto,1") in new stack -- Executing [[email protected]:38] GotoIf("SIP/2065551212_VOIPO-00000000", "1?godial") in new stack -- Goto (macro-dial-one,s,42) -- Executing [[email protected]:42] Dial("SIP/2065551212_VOIPO-00000000", "SIP/8881,28,Ttr") in new stack == Using SIP RTP TOS bits 184 == Using SIP RTP CoS mark 5 -- Called SIP/8881 == Everyone is busy/congested at this time (1:0/0/1) -- Executing [[email protected]:43] ExecIf("SIP/2065551212_VOIPO-00000000", "0?MacroExit()") in new stack -- Executing [[email protected]:44] ExecIf("SIP/2065551212_VOIPO-00000000", "0?Set(DIALSTATUS=)") in new stack -- Executing [[email protected]:45] GosubIf("SIP/2065551212_VOIPO-00000000", "0?s-CHANUNAVAIL,1()") in new stack -- Executing [[email protected]:46] MacroExit("SIP/2065551212_VOIPO-00000000", "") in new stack -- Executing [[email protected]:17] Set("SIP/2065551212_VOIPO-00000000", "SV_DIALSTATUS=CHANUNAVAIL") in new stack -- Executing [[email protected]:18] GosubIf("SIP/2065551212_VOIPO-00000000", "0?docfu,1()") in new stack -- Executing [[email protected]:19] GosubIf("SIP/2065551212_VOIPO-00000000", "0?docfb,1()") in new stack -- Executing [[email protected]:20] Set("SIP/2065551212_VOIPO-00000000", "DIALSTATUS=CHANUNAVAIL") in new stack -- Executing [[email protected]:21] ExecIf("SIP/2065551212_VOIPO-00000000", "0?MacroExit()") in new stack -- Executing [[email protected]:22] GotoIf("SIP/2065551212_VOIPO-00000000", "0?s-CHANUNAVAIL,1") in new stack -- Executing [[email protected]:23] Macro("SIP/2065551212_VOIPO-00000000", "vm,8881,CHANUNAVAIL,") in new stack -- Executing [[email protected]:1] Macro("SIP/2065551212_VOIPO-00000000", "user-callerid,SKIPTTL") in new stack -- Executing [[email protected]:1] Set("SIP/2065551212_VOIPO-00000000", "TOUCH_MONITOR=1380064195.0") in new stack -- Executing [[email protected]:2] Set("SIP/2065551212_VOIPO-00000000", "AMPUSER=2065551234") in new stack -- Executing [[email protected]:3] GotoIf("SIP/2065551212_VOIPO-00000000", "0?report") in new stack -- Executing [[email protected]:4] ExecIf("SIP/2065551212_VOIPO-00000000", "0?Set(REALCALLERIDNUM=2065551234)") in new stack -- Executing [[email protected]:5] Set("SIP/2065551212_VOIPO-00000000", "AMPUSER=") in new stack -- Executing [[email protected]:6] Set("SIP/2065551212_VOIPO-00000000", "AMPUSERCIDNAME=") in new stack -- Executing [[email protected]:7] GotoIf("SIP/2065551212_VOIPO-00000000", "1?report") in new stack -- Goto (macro-user-callerid,s,15) -- Executing [[email protected]:15] GotoIf("SIP/2065551212_VOIPO-00000000", "1?continue") in new stack -- Goto (macro-user-callerid,s,28) -- Executing [[email protected]:28] Set("SIP/2065551212_VOIPO-00000000", "CALLERID(number)=2065551234") in new stack -- Executing [[email protected]:29] Set("SIP/2065551212_VOIPO-00000000", "CALLERID(name)=SEATTLE WA") in new stack -- Executing [[email protected]:30] Set("SIP/2065551212_VOIPO-00000000", "CDR(cnum)=2065551234") in new stack -- Executing [[email protected]:31] Set("SIP/2065551212_VOIPO-00000000", "CDR(cnam)=SEATTLE WA") in new stack -- Executing [[email protected]:32] Set("SIP/2065551212_VOIPO-00000000", "CHANNEL(language)=en") in new stack -- Executing [[email protected]:2] Set("SIP/2065551212_VOIPO-00000000", "VMGAIN=") in new stack -- Executing [[email protected]:3] Macro("SIP/2065551212_VOIPO-00000000", "blkvm-check,") in new stack -- Executing [[email protected]:1] Set("SIP/2065551212_VOIPO-00000000", "GOSUB_RETVAL=") in new stack -- Executing [[email protected]:2] ExecIf("SIP/2065551212_VOIPO-00000000", "0?Set(GOSUB_RETVAL=TRUE)") in new stack -- Executing [[email protected]:3] MacroExit("SIP/2065551212_VOIPO-00000000", "") in new stack -- Executing [[email protected]:4] GotoIf("SIP/2065551212_VOIPO-00000000", "1?vmx,1") in new stack -- Goto (macro-vm,vmx,1) -- Executing [[email protected]:1] Set("SIP/2065551212_VOIPO-00000000", "MEXTEN=8881") in new stack -- Executing [[email protected]:2] Set("SIP/2065551212_VOIPO-00000000", "MMODE=CHANUNAVAIL") in new stack -- Executing [[email protected]:3] Set("SIP/2065551212_VOIPO-00000000", "RETVM=") in new stack -- Executing [[email protected]:4] Set("SIP/2065551212_VOIPO-00000000", "MODE=unavail") in new stack -- Executing [[email protected]:5] GotoIf("SIP/2065551212_VOIPO-00000000", "1?chknomsg") in new stack -- Goto (macro-vm,vmx,7) -- Executing [[email protected]:7] GotoIf("SIP/2065551212_VOIPO-00000000", "0?s-CHANUNAVAIL,1") in new stack -- Executing [[email protected]:8] GotoIf("SIP/2065551212_VOIPO-00000000", "1?notdirect") in new stack -- Goto (macro-vm,vmx,10) -- Executing [[email protected]:10] NoOp("SIP/2065551212_VOIPO-00000000", "Checking if ext 8881 is enabled: ") in new stack -- Executing [[email protected]:11] GotoIf("SIP/2065551212_VOIPO-00000000", "1?s-CHANUNAVAIL,1") in new stack -- Goto (macro-vm,s-CHANUNAVAIL,1) -- Executing [[email protected]:1] Macro("SIP/2065551212_VOIPO-00000000", "get-vmcontext,8881") in new stack -- Executing [[email protected]:1] Set("SIP/2065551212_VOIPO-00000000", "VMCONTEXT=default") in new stack -- Executing [[email protected]:2] GotoIf("SIP/2065551212_VOIPO-00000000", "0?200:300") in new stack -- Goto (macro-get-vmcontext,s,300) -- Executing [[email protected]:300] NoOp("SIP/2065551212_VOIPO-00000000", "") in new stack -- Executing [[email protected]:2] VoiceMail("SIP/2065551212_VOIPO-00000000", "[email protected],u") in new stack -- Playing 'vm-theperson.ulaw' (language 'en') -- Playing 'digits/8.ulaw' (language 'en') -- Playing 'digits/8.ulaw' (language 'en') -- Playing 'digits/8.ulaw' (language 'en') -- Playing 'digits/1.ulaw' (language 'en') -- Playing 'vm-isunavail.ulaw' (language 'en') -- Playing 'vm-intro.ulaw' (language 'en') == Spawn extension (macro-vm, s-CHANUNAVAIL, 2) exited non-zero on 'SIP/2065551212_VOIPO-00000000' in macro 'vm' == Spawn extension (macro-exten-vm, s, 23) exited non-zero on 'SIP/2065551212_VOIPO-00000000' in macro 'exten-vm' == Spawn extension (from-did-direct, 8881, 2) exited non-zero on 'SIP/2065551212_VOIPO-00000000' -- Executing [[email protected]:1] Macro("SIP/2065551212_VOIPO-00000000", "hangupcall,") in new stack -- Executing [[email protected]:1] GotoIf("SIP/2065551212_VOIPO-00000000", "1?theend") in new stack -- Goto (macro-hangupcall,s,3) -- Executing [[email protected]:3] ExecIf("SIP/2065551212_VOIPO-00000000", "0?Set(CDR(recordingfile)=)") in new stack -- Executing [[email protected]:4] Hangup("SIP/2065551212_VOIPO-00000000", "") in new stack == Spawn extension (macro-hangupcall, s, 4) exited non-zero on 'SIP/2065551212_VOIPO-00000000' in macro 'hangupcall' == Spawn extension (from-did-direct, h, 1) exited non-zero on 'SIP/2065551212_VOIPO-00000000'

These logs just say that your called ended up trying a sip connection to 8881, it apparently was apparently “busy/congested” so it went to voicemail.

Thanks Dicko. So how can it be busy/congested when no one else is using it? Is there anything in the system that can cause it to be treated as busy? Anything I need to watch or reset? I restart the amportal many times already to no avail. Pls advise?

8881 will be considered busy/unavailable for many reasons, if it is not off-hook and has call waiting enabled , then

sip show peers

or more specifically

sip show peer 8881

from the asterisk CLI will help you diagnose.

Thanks dicko.

This is what I gather from sip show peer 8881. Not sure how to decode it. Pls advise? Many thanks in advance again for all of your help?

Name : 8881 Description : Secret : MD5Secret : Remote Secret: Context : from-internal Record On feature : automon Record Off feature : automon Subscr.Cont. : Language : Tonezone : AMA flags : Unknown Transfer mode: open CallingPres : Presentation Allowed, Not Screened Callgroup : Pickupgroup : Named Callgr : Nam. Pickupgr: MOH Suggest : Mailbox : [email protected] VM Extension : *97 LastMsgsSent : 0/0 Call limit : 2147483647 Max forwards : 0 Dynamic : Yes Callerid : 2065551212 MaxCallBR : 384 kbps Expire : 1146 Insecure : no Force rport : Yes Symmetric RTP: Yes ACL : Yes DirectMedACL : No T.38 support : No T.38 EC mode : Unknown T.38 MaxDtgrm: -1 DirectMedia : No PromiscRedir : No User=Phone : No Video Support: No Text Support : No Ign SDP ver : No Trust RPID : Yes Send RPID : No Subscriptions: Yes Overlap dial : Yes DTMFmode : rfc2833 Timer T1 : 500 Timer B : 32000 ToHost : Addr->IP : 50.47.0.193:5070 Defaddr->IP : (null) Prim.Transp. : UDP Allowed.Trsp : UDP Def. Username: 25384617 SIP Options : (none) Codecs : (g723|gsm|ulaw|alaw|g726) Codec Order : (ulaw:20,alaw:20,gsm:20,g723:30,g726:20) Auto-Framing : No Status : Unmonitored Useragent : Grandstream HT286 1.0.6.7 Reg. Contact : sip:[email protected]:5070 Qualify Freq : 30000 ms Keepalive : 0 ms Sess-Timers : Accept Sess-Refresh : uas Sess-Expires : 1800 secs Min-Sess : 90 secs RTP Engine : asterisk Parkinglot : Use Reason : No Encryption : No

It’s still happening. all of sudden it works once, then after that, none. Phone never ring, straight to VM. Sounds like something get stuck once a phone call comes in, picked up and hung up. But the status never reset to available. Is there anyway I can check? Please help?

I notice that your endpoint is using SIP registration over 5070, is your server in agreement on that extension?

Yes it does. I open up port 5070 on the server and my ATA end. If firewall is the issue, doesn’t explain why sometime it works sometime it doesn’t though. Thanks dicko.

Do you have any form of “sip helper” on your firewall, rarely are the helpful :wink:

Not that I know of dicko. Just a standard iptables that comes with centos 6.4 64bit. Out of curiosity.
Also, I just noticed this a minute ago. I have my ata and softphone connected to the 8881 extension. I have my softphone ringing just now but not my ata. Is it possible that freepbx might get confused and it only rang one or the others? [size= 15px; line-height: 1.5em] Is there a way to make it so that an extension can accept as many share connection as possible if it’s not already built that way? Many thanks again dicko…[/size]

Are you saying you have both the soft phone and the ATA registered as the same extension? You can’t have two devices registered to the same extension like that.

There is your problem, you can’t do that, read the wiki and pay attention to ring groups.

Thanks alan_mousty and dicko. I’ve forgotten about my softphone connected to that extension. Thus I was banging my head wondering why. Until my softphone ring and home phone didn’t I just realized that that phone is connected. So is there a way in freepbx configuration to lock the login to just one device so that accidental like this won’t happen again? Just curious. Many thanks again.