In the following log the number is ringing busy. I have a DID setup for 18622466913. I have another DID on this SIP and I am able to grab that one just fine. What am I doing wrong? Thanks.
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Executing [18622466913@from-trunk:1] Set(“SIP/smason-09ae4140”, “__FROM_DID=18622466913”) in new stack
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Executing [18622466913@from-trunk:2] Gosub(“SIP/smason-09ae4140”, “cidlookup|cidlookup_4|1()”) in new stack
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Executing [cidlookup_4@cidlookup:1] Set(“SIP/smason-09ae4140”, "CALLERID(name)=Mason Simon ") in new stack
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Executing [cidlookup_4@cidlookup:2] Return(“SIP/smason-09ae4140”, “”) in new stack
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Executing [18622466913@from-trunk:3] Gosub(“SIP/smason-09ae4140”, “app-blacklist-check|s|1()”) in new stack
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Executing [s@app-blacklist-check:1] LookupBlacklist(“SIP/smason-09ae4140”, “”) in new stack
[2012-07-18 20:40:25] WARNING[7948] app_lookupblacklist.c: LookupBlacklist is deprecated. Please use ${BLACKLIST()} instead.
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Executing [s@app-blacklist-check:2] GotoIf(“SIP/smason-09ae4140”, “0?blacklisted”) in new stack
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Executing [s@app-blacklist-check:3] Set(“SIP/smason-09ae4140”, “CALLED_BLACKLIST=1”) in new stack
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Executing [s@app-blacklist-check:4] Return(“SIP/smason-09ae4140”, “”) in new stack
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Executing [18622466913@from-trunk:4] Set(“SIP/smason-09ae4140”, “CDR(did)=18622466913”) in new stack
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Executing [18622466913@from-trunk:5] ExecIf(“SIP/smason-09ae4140”, “0 |Set|CALLERID(name)=9737223860”) in new stack
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Executing [18622466913@from-trunk:6] Macro(“SIP/smason-09ae4140”, “privacy-mgr|3|7”) in new stack
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Executing [s@macro-privacy-mgr:1] Set(“SIP/smason-09ae4140”, “KEEPCID=9737223860”) in new stack
[2012-07-18 20:40:25] DEBUG[7948] app_macro.c: Executed application: Set
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Executing [s@macro-privacy-mgr:2] GotoIf(“SIP/smason-09ae4140”, “0?CIDTEST2:CIDTEST1”) in new stack
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Goto (macro-privacy-mgr,s,3)
[2012-07-18 20:40:25] DEBUG[7948] app_macro.c: Executed application: GotoIf
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Executing [s@macro-privacy-mgr:3] Set(“SIP/smason-09ae4140”, “TESTCID=9737223861.000000”) in new stack
[2012-07-18 20:40:25] DEBUG[7948] app_macro.c: Executed application: Set
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Executing [s@macro-privacy-mgr:4] Goto(“SIP/smason-09ae4140”, “TESTRESULT”) in new stack
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Goto (macro-privacy-mgr,s,6)
[2012-07-18 20:40:25] DEBUG[7948] app_macro.c: Executed application: Goto
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Executing [s@macro-privacy-mgr:6] GotoIf(“SIP/smason-09ae4140”, “0?CLEARCID:PRIVMGR”) in new stack
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Goto (macro-privacy-mgr,s,8)
[2012-07-18 20:40:25] DEBUG[7948] app_macro.c: Executed application: GotoIf
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Executing [s@macro-privacy-mgr:8] PrivacyManager(“SIP/smason-09ae4140”, “3|7”) in new stack
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – CallerID Present: Skipping
[2012-07-18 20:40:25] DEBUG[7948] app_macro.c: Executed application: PrivacyManager
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Executing [s@macro-privacy-mgr:9] GotoIf(“SIP/smason-09ae4140”, “0?fail”) in new stack
[2012-07-18 20:40:25] DEBUG[7948] app_macro.c: Executed application: GotoIf
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Executing [s@macro-privacy-mgr:10] GosubIf(“SIP/smason-09ae4140”, “1?app-blacklist-check|s|1”) in new stack
[2012-07-18 20:40:25] DEBUG[7948] app_macro.c: Executed application: GosubIf
[2012-07-18 20:40:25] DEBUG[7948] app_macro.c: Incrementing gosub_level
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Executing [s@app-blacklist-check:1] LookupBlacklist(“SIP/smason-09ae4140”, “”) in new stack
[2012-07-18 20:40:25] DEBUG[7948] app_macro.c: Executed application: LookupBlacklist
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Executing [s@app-blacklist-check:2] GotoIf(“SIP/smason-09ae4140”, “0?blacklisted”) in new stack
[2012-07-18 20:40:25] DEBUG[7948] app_macro.c: Executed application: GotoIf
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Executing [s@app-blacklist-check:3] Set(“SIP/smason-09ae4140”, “CALLED_BLACKLIST=1”) in new stack
[2012-07-18 20:40:25] DEBUG[7948] app_macro.c: Executed application: Set
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Executing [s@app-blacklist-check:4] Return(“SIP/smason-09ae4140”, “”) in new stack
[2012-07-18 20:40:25] DEBUG[7948] app_macro.c: Executed application: Return
[2012-07-18 20:40:25] DEBUG[7948] app_macro.c: Decrementing gosub_level
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Executing [s@macro-privacy-mgr:11] SetCallerPres(“SIP/smason-09ae4140”, “allowed_passed_screen”) in new stack
[2012-07-18 20:40:25] DEBUG[7948] app_macro.c: Executed application: SetCallerPres
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Executing [18622466913@from-trunk:7] Goto(“SIP/smason-09ae4140”, “from-did-direct|221|1”) in new stack
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Goto (from-did-direct,221,1)
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Executing [221@from-did-direct:1] Set(“SIP/smason-09ae4140”, “__RINGTIMER=8”) in new stack
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Executing [221@from-did-direct:2] Macro(“SIP/smason-09ae4140”, “exten-vm|novm|221|0|0|0”) in new stack
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Executing [s@macro-exten-vm:1] Macro(“SIP/smason-09ae4140”, “user-callerid|”) in new stack
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Executing [s@macro-user-callerid:1] Set(“SIP/smason-09ae4140”, “AMPUSER=9737223860”) in new stack
[2012-07-18 20:40:25] DEBUG[7948] app_macro.c: Executed application: Set
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Executing [s@macro-user-callerid:2] GotoIf(“SIP/smason-09ae4140”, “0?report”) in new stack
[2012-07-18 20:40:25] DEBUG[7948] app_macro.c: Executed application: GotoIf
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Executing [s@macro-user-callerid:3] ExecIf(“SIP/smason-09ae4140”, “1|Set|REALCALLERIDNUM=9737223860”) in new stack
[2012-07-18 20:40:25] DEBUG[7948] app_macro.c: Executed application: ExecIf
[2012-07-18 20:40:25] DEBUG[7948] func_db.c: DB: DEVICE/9737223860/user not found in database.
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Executing [s@macro-user-callerid:4] Set(“SIP/smason-09ae4140”, “AMPUSER=”) in new stack
[2012-07-18 20:40:25] DEBUG[7948] app_macro.c: Executed application: Set
[2012-07-18 20:40:25] DEBUG[7948] func_db.c: DB: AMPUSER//cidname not found in database.
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Executing [s@macro-user-callerid:5] Set(“SIP/smason-09ae4140”, “AMPUSERCIDNAME=”) in new stack
[2012-07-18 20:40:25] DEBUG[7948] app_macro.c: Executed application: Set
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Executing [s@macro-user-callerid:6] GotoIf(“SIP/smason-09ae4140”, “1?report”) in new stack
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Goto (macro-user-callerid,s,12)
[2012-07-18 20:40:25] DEBUG[7948] app_macro.c: Executed application: GotoIf
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Executing [s@macro-user-callerid:12] GotoIf(“SIP/smason-09ae4140”, “0?continue”) in new stack
[2012-07-18 20:40:25] DEBUG[7948] app_macro.c: Executed application: GotoIf
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Executing [s@macro-user-callerid:13] Set(“SIP/smason-09ae4140”, “__TTL=64”) in new stack
[2012-07-18 20:40:25] DEBUG[7948] app_macro.c: Executed application: Set
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Executing [s@macro-user-callerid:14] GotoIf(“SIP/smason-09ae4140”, “1?continue”) in new stack
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Goto (macro-user-callerid,s,25)
[2012-07-18 20:40:25] DEBUG[7948] app_macro.c: Executed application: GotoIf
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Executing [s@macro-user-callerid:25] Set(“SIP/smason-09ae4140”, “CALLERID(number)=9737223860”) in new stack
[2012-07-18 20:40:25] DEBUG[7948] app_macro.c: Executed application: Set
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Executing [s@macro-user-callerid:26] Set(“SIP/smason-09ae4140”, "CALLERID(name)=Mason Simon ") in new stack
[2012-07-18 20:40:25] DEBUG[7948] app_macro.c: Executed application: Set
[2012-07-18 20:40:25] DEBUG[7948] app_macro.c: Executed application: Macro
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Executing [s@macro-exten-vm:2] Set(“SIP/smason-09ae4140”, “RingGroupMethod=none”) in new stack
[2012-07-18 20:40:25] DEBUG[7948] app_macro.c: Executed application: Set
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Executing [s@macro-exten-vm:3] Set(“SIP/smason-09ae4140”, “__EXTTOCALL=221”) in new stack
[2012-07-18 20:40:25] DEBUG[7948] app_macro.c: Executed application: Set
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Executing [s@macro-exten-vm:4] Set(“SIP/smason-09ae4140”, “__PICKUPMARK=221”) in new stack
[2012-07-18 20:40:25] DEBUG[7948] app_macro.c: Executed application: Set
[2012-07-18 20:40:25] DEBUG[7948] func_db.c: DB: CFU/221 not found in database.
[2012-07-18 20:40:25] DEBUG[7948] func_db.c: DB: CFB/221 not found in database.
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Executing [s@macro-exten-vm:5] Set(“SIP/smason-09ae4140”, “RT=”) in new stack
[2012-07-18 20:40:25] DEBUG[7948] app_macro.c: Executed application: Set
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Executing [s@macro-exten-vm:6] Gosub(“SIP/smason-09ae4140”, “sub-record-check|s|1(exten|221|)”) in new stack
[2012-07-18 20:40:25] DEBUG[7948] app_macro.c: Executed application: Gosub
[2012-07-18 20:40:25] DEBUG[7948] app_macro.c: Incrementing gosub_level
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Executing [s@sub-record-check:1] GotoIf(“SIP/smason-09ae4140”, “1?check”) in new stack
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Goto (sub-record-check,s,6)
[2012-07-18 20:40:25] DEBUG[7948] app_macro.c: Executed application: GotoIf
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Executing [s@sub-record-check:6] Set(“SIP/smason-09ae4140”, “__MON_FMT=wav”) in new stack
[2012-07-18 20:40:25] DEBUG[7948] app_macro.c: Executed application: Set
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Executing [s@sub-record-check:7] GotoIf(“SIP/smason-09ae4140”, “1?next”) in new stack
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Goto (sub-record-check,s,10)
[2012-07-18 20:40:25] DEBUG[7948] app_macro.c: Executed application: GotoIf
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Executing [s@sub-record-check:10] ExecIf(“SIP/smason-09ae4140”, “0|Return|”) in new stack
[2012-07-18 20:40:25] DEBUG[7948] app_macro.c: Executed application: ExecIf
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Executing [s@sub-record-check:11] GotoIf(“SIP/smason-09ae4140”, “0?novm|1”) in new stack
[2012-07-18 20:40:25] DEBUG[7948] app_macro.c: Executed application: GotoIf
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Executing [s@sub-record-check:12] Set(“SIP/smason-09ae4140”, “__REC_STATUS=INITIALIZED”) in new stack
[2012-07-18 20:40:25] DEBUG[7948] app_macro.c: Executed application: Set
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Executing [s@sub-record-check:13] ExecIf(“SIP/smason-09ae4140”, “1|Set|__REC_POLICY_MODE=0”) in new stack
[2012-07-18 20:40:25] DEBUG[7948] app_macro.c: Executed application: ExecIf
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Executing [s@sub-record-check:14] Set(“SIP/smason-09ae4140”, “NOW=1342658425”) in new stack
[2012-07-18 20:40:25] DEBUG[7948] app_macro.c: Executed application: Set
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Executing [s@sub-record-check:15] Set(“SIP/smason-09ae4140”, “__DAY=18”) in new stack
[2012-07-18 20:40:25] DEBUG[7948] app_macro.c: Executed application: Set
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Executing [s@sub-record-check:16] Set(“SIP/smason-09ae4140”, “__MONTH=07”) in new stack
[2012-07-18 20:40:25] DEBUG[7948] app_macro.c: Executed application: Set
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Executing [s@sub-record-check:17] Set(“SIP/smason-09ae4140”, “__YEAR=2012”) in new stack
[2012-07-18 20:40:25] DEBUG[7948] app_macro.c: Executed application: Set
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Executing [s@sub-record-check:18] Set(“SIP/smason-09ae4140”, “__TIMESTR=20120718-204025”) in new stack
[2012-07-18 20:40:25] DEBUG[7948] app_macro.c: Executed application: Set
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Executing [s@sub-record-check:19] Set(“SIP/smason-09ae4140”, “__FROMEXTEN=9737223860”) in new stack
[2012-07-18 20:40:25] DEBUG[7948] app_macro.c: Executed application: Set
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Executing [s@sub-record-check:20] Set(“SIP/smason-09ae4140”, “__CALLFILENAME=novm-221-9737223860-20120718-204025-1342658425.1”) in new stack
[2012-07-18 20:40:25] DEBUG[7948] app_macro.c: Executed application: Set
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Executing [s@sub-record-check:21] Goto(“SIP/smason-09ae4140”, “novm|1”) in new stack
[2012-07-18 20:40:25] VERBOSE[7948] logger.c: – Goto (sub-record-check,novm,1)
[2012-07-18 20:40:25] DEBUG[7948] app_macro.c: Executed application: Goto
[2012-07-18 20:40:25] WARNING[7948] pbx.c: Channel ‘SIP/smason-09ae4140’ sent into invalid extension ‘novm’ in context ‘sub-record-check’, but no invalid handler
[2012-07-18 20:40:25] VERBOSE[7947] logger.c: == Manager ‘admin’ logged off from 127.0.0.1
[2012-07-18 20:40:32] VERBOSE[7958] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: [2012-07-18 20:40:32] VERBOSE[7958] logger.c: Found
[2012-07-18 20:40:32] VERBOSE[7958] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: [2012-07-18 20:40:32] VERBOSE[7958] logger.c: Found
[2012-07-18 20:40:32] VERBOSE[7958] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: [2012-07-18 20:40:32] VERBOSE[7958] logger.c: Found