UK Caller ID (again!) - Head. Wall. Banging etc

Hey all.

I’m currently testing FreePBX as a replacement to my company’s ageing telephone system. I’m using a desktop PC with FreePBX 3.211.63-10 installed. Also installed is a Sangoma A200 (2 x FXO ports).
I have 1 sip trunk and one POTS (BT) line connected. Caller ID works fine on SIP trunk but not on the POTS. I have searched and searched and tweaked and patch. Here are some of the links I have followed.

http://automation.binarysage.net/?p=232


http://www.voip-info.org/wiki/view/Asterisk+and+UK+Caller+ID
http://wiki.sangoma.com/wanpipe-linux-asterisk-debugging#analog-caller-id-issues
Thats not a full list but you can imagine.
Below is the output of the logfile when I try and make an incoming call. What am I missing??

[2013-06-13 12:55:13] VERBOSE[2232][C-00000003] sig_analog.c: == Starting post polarity CID detection on channel 1
[2013-06-13 12:55:13] VERBOSE[4356][C-00000003] sig_analog.c: – Starting simple switch on ‘DAHDI/1-1’
[2013-06-13 12:55:18] NOTICE[4356][C-00000003] chan_dahdi.c: Got event 18 (Ring Begin)…
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] chan_dahdi.c: – Detected ring pattern: 0,0,0
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] chan_dahdi.c: – Checking 0,0,0
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] chan_dahdi.c: – Ring pattern check range: 10
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] chan_dahdi.c: – Ring pattern matched in range: -10 to 10
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] chan_dahdi.c: – Ring pattern check range: 10
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] chan_dahdi.c: – Ring pattern matched in range: -10 to 10
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] chan_dahdi.c: – Ring pattern check range: 10
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] chan_dahdi.c: – Ring pattern matched in range: -10 to 10
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] chan_dahdi.c: – Distinctive Ring matched context from-analog
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [s@from-analog:1] NoOp(“DAHDI/1-1”, "Entering from-dahdi with DID == ") in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [s@from-analog:2] Ringing(“DAHDI/1-1”, “”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [s@from-analog:3] Set(“DAHDI/1-1”, “DID=s”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [s@from-analog:4] NoOp(“DAHDI/1-1”, “DID is now s”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [s@from-analog:5] GotoIf(“DAHDI/1-1”, “1?dahdiok:checkzap”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Goto (from-analog,s,9)
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [s@from-analog:9] NoOp(“DAHDI/1-1”, “Is a DAHDi Channel”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [s@from-analog:10] Set(“DAHDI/1-1”, “CHAN=1-1”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [s@from-analog:11] Set(“DAHDI/1-1”, “CHAN=1”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [s@from-analog:12] Macro(“DAHDI/1-1”, “from-dahdi-1,s,1”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [s@macro-from-dahdi-1:1] NoOp(“DAHDI/1-1”, “Entering macro-from-dahdi-1 with DID = s and setting to: 01707251900”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [s@macro-from-dahdi-1:2] Set(“DAHDI/1-1”, “__FROM_DID=01707251900”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [s@macro-from-dahdi-1:3] Goto(“DAHDI/1-1”, “from-trunk,01707251900,1”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Goto (from-trunk,01707251900,1)
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] app_macro.c: == Channel ‘DAHDI/1-1’ jumping out of macro ‘from-dahdi-1’
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [01707251900@from-trunk:1] NoOp(“DAHDI/1-1”, “Catch-All DID Match - Found 01707251900 - You probably want a DID for this.”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [01707251900@from-trunk:2] Goto(“DAHDI/1-1”, “ext-did,s,1”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Goto (ext-did,s,1)
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [s@ext-did:1] ExecIf(“DAHDI/1-1”, “0?Set(__FROM_DID=s)”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [s@ext-did:2] Gosub(“DAHDI/1-1”, “app-blacklist-check,s,1()”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [s@app-blacklist-check:1] GotoIf(“DAHDI/1-1”, “0?blacklisted”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [s@app-blacklist-check:2] Set(“DAHDI/1-1”, “CALLED_BLACKLIST=1”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [s@app-blacklist-check:3] Return(“DAHDI/1-1”, “”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [s@ext-did:3] Set(“DAHDI/1-1”, “CDR(did)=01707251900”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [s@ext-did:4] ExecIf(“DAHDI/1-1”, “1 ?Set(CALLERID(name)=)”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [s@ext-did:5] Set(“DAHDI/1-1”, “__CALLINGPRES_SV=allowed_not_screened”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [s@ext-did:6] Set(“DAHDI/1-1”, “CALLERPRES()=allowed_not_screened”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [s@ext-did:7] Goto(“DAHDI/1-1”, “ext-queues,500,1”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Goto (ext-queues,500,1)
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [500@ext-queues:1] Macro(“DAHDI/1-1”, “user-callerid,”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [s@macro-user-callerid:1] Set(“DAHDI/1-1”, “TOUCH_MONITOR=1371124513.10”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [s@macro-user-callerid:2] Set(“DAHDI/1-1”, “AMPUSER=”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [s@macro-user-callerid:3] GotoIf(“DAHDI/1-1”, “0?report”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [s@macro-user-callerid:4] ExecIf(“DAHDI/1-1”, “1?Set(REALCALLERIDNUM=)”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [s@macro-user-callerid:5] Set(“DAHDI/1-1”, “AMPUSER=”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [s@macro-user-callerid:6] Set(“DAHDI/1-1”, “AMPUSERCIDNAME=”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [s@macro-user-callerid:7] GotoIf(“DAHDI/1-1”, “1?report”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Goto (macro-user-callerid,s,15)
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [s@macro-user-callerid:15] GotoIf(“DAHDI/1-1”, “0?continue”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [s@macro-user-callerid:16] Set(“DAHDI/1-1”, “__TTL=64”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [s@macro-user-callerid:17] GotoIf(“DAHDI/1-1”, “1?continue”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Goto (macro-user-callerid,s,28)
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [s@macro-user-callerid:28] Set(“DAHDI/1-1”, “CALLERID(number)=”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [s@macro-user-callerid:29] Set(“DAHDI/1-1”, “CALLERID(name)=”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [s@macro-user-callerid:30] Set(“DAHDI/1-1”, “CDR(cnum)=”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [s@macro-user-callerid:31] Set(“DAHDI/1-1”, “CDR(cnam)=”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [s@macro-user-callerid:32] Set(“DAHDI/1-1”, “CHANNEL(language)=en”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [500@ext-queues:2] Answer(“DAHDI/1-1”, “”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [500@ext-queues:3] Macro(“DAHDI/1-1”, “blkvm-set,reset”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [s@macro-blkvm-set:1] ExecIf(“DAHDI/1-1”, “1?Set(__BLKVM_CHANNEL=DAHDI/1-1)”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [s@macro-blkvm-set:2] Set(“DAHDI/1-1”, “SHARED(BLKVM,DAHDI/1-1)=TRUE”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [s@macro-blkvm-set:3] Set(“DAHDI/1-1”, “GOSUB_RETVAL=TRUE”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [s@macro-blkvm-set:4] MacroExit(“DAHDI/1-1”, “”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [500@ext-queues:4] ExecIf(“DAHDI/1-1”, “1?Set(_DIAL_OPTIONS=TtrM(auto-blkvm))”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [500@ext-queues:5] Set(“DAHDI/1-1”, “__NODEST=500”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [500@ext-queues:6] Set(“DAHDI/1-1”, “QCIDPP=External:”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [500@ext-queues:7] ExecIf(“DAHDI/1-1”, “1?Macro(prepend-cid, External:)”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [s@macro-prepend-cid:1] GotoIf(“DAHDI/1-1”, “1?REPCID”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Goto (macro-prepend-cid,s,5)
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [s@macro-prepend-cid:5] Set(“DAHDI/1-1”, “_RGPREFIX= External:”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [s@macro-prepend-cid:6] Set(“DAHDI/1-1”, “CALLERID(name)= External:”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [500@ext-queues:8] Set(“DAHDI/1-1”, “QAINFO=”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [500@ext-queues:9] ExecIf(“DAHDI/1-1”, “0?Set(__ALERT_INFO=)”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [500@ext-queues:10] Set(“DAHDI/1-1”, “QJOINMSG=.asterisk-core-sounds-en-alaw-1.4.21”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [500@ext-queues:11] Set(“DAHDI/1-1”, “QMOH=default”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [500@ext-queues:12] ExecIf(“DAHDI/1-1”, “1?Set(__MOHCLASS=default)”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [500@ext-queues:13] Set(“DAHDI/1-1”, “QCANCELMISSED=C”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [500@ext-queues:14] Set(“DAHDI/1-1”, “QRETRY=”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [500@ext-queues:15] Set(“DAHDI/1-1”, “QOPTIONS=tC”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [500@ext-queues:16] Set(“DAHDI/1-1”, “QAGI=”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [500@ext-queues:17] Set(“DAHDI/1-1”, “QRULE=”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [500@ext-queues:18] Set(“DAHDI/1-1”, “QPOSITION=”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [500@ext-queues:19] Gosub(“DAHDI/1-1”, “sub-record-check,s,1(q,500,dontcare)”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [s@sub-record-check:1] Set(“DAHDI/1-1”, “REC_POLICY_MODE_SAVE=”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [s@sub-record-check:2] GotoIf(“DAHDI/1-1”, “1?check”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Goto (sub-record-check,s,7)
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [s@sub-record-check:7] Set(“DAHDI/1-1”, “__MON_FMT=wav”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [s@sub-record-check:8] GotoIf(“DAHDI/1-1”, “1?next”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Goto (sub-record-check,s,11)
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [s@sub-record-check:11] ExecIf(“DAHDI/1-1”, “0?Return()”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [s@sub-record-check:12] ExecIf(“DAHDI/1-1”, “1?Set(__REC_POLICY_MODE=dontcare)”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [s@sub-record-check:13] GotoIf(“DAHDI/1-1”, “0?q,1”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [s@sub-record-check:14] Set(“DAHDI/1-1”, “__REC_STATUS=INITIALIZED”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [s@sub-record-check:15] Set(“DAHDI/1-1”, “NOW=1371124518”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [s@sub-record-check:16] Set(“DAHDI/1-1”, “__DAY=13”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [s@sub-record-check:17] Set(“DAHDI/1-1”, “__MONTH=06”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [s@sub-record-check:18] Set(“DAHDI/1-1”, “__YEAR=2013”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [s@sub-record-check:19] Set(“DAHDI/1-1”, “__TIMESTR=20130613-125518”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [s@sub-record-check:20] Set(“DAHDI/1-1”, “__FROMEXTEN=unknown”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [s@sub-record-check:21] Set(“DAHDI/1-1”, “__CALLFILENAME=q-500-unknown-20130613-125518-1371124513.10”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [s@sub-record-check:22] Goto(“DAHDI/1-1”, “q,1”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Goto (sub-record-check,q,1)
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [q@sub-record-check:1] GosubIf(“DAHDI/1-1”, “0?recq,1(q,500,unknown)”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [q@sub-record-check:2] Return(“DAHDI/1-1”, “”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [500@ext-queues:20] Set(“DAHDI/1-1”, “__CWIGNORE=TRUE”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [500@ext-queues:21] ExecIf(“DAHDI/1-1”, “1?Playback(.asterisk-core-sounds-en-alaw-1.4.21, )”) in new stack
[2013-06-13 12:55:18] WARNING[4356][C-00000003] file.c: File .asterisk-core-sounds-en-alaw-1.4.21 does not exist in any format
[2013-06-13 12:55:18] WARNING[4356][C-00000003] file.c: Unable to open .asterisk-core-sounds-en-alaw-1.4.21 (format (alaw)): No such file or directory
[2013-06-13 12:55:18] WARNING[4356][C-00000003] app_playback.c: ast_streamfile failed on DAHDI/1-1 for .asterisk-core-sounds-en-alaw-1.4.21,
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [500@ext-queues:22] QueueLog(“DAHDI/1-1”, “500,1371124513.10,NONE,DID,01707251900”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [500@ext-queues:23] Set(“DAHDI/1-1”, “QAANNOUNCE=”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] pbx.c: – Executing [500@ext-queues:24] Queue(“DAHDI/1-1”, “500,tC,”) in new stack
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] res_musiconhold.c: – Started music on hold, class ‘default’, on DAHDI/1-1
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] app_queue.c: – Called Local/200@from-queue/n
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [200@from-queue:1] Set(“Local/200@from-queue-00000002;2”, “QAGENT=200”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [200@from-queue:2] Goto(“Local/200@from-queue-00000002;2”, “500,1”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Goto (from-queue,500,1)
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [500@from-queue:1] Goto(“Local/200@from-queue-00000002;2”, “from-internal,200,1”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Goto (from-internal,200,1)
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [200@from-internal:1] Set(“Local/200@from-queue-00000002;2”, “__RINGTIMER=15”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [200@from-internal:2] Macro(“Local/200@from-queue-00000002;2”, “exten-vm,200,200,0,0,0”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [s@macro-exten-vm:1] Macro(“Local/200@from-queue-00000002;2”, “user-callerid,”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [s@macro-user-callerid:1] Set(“Local/200@from-queue-00000002;2”, “TOUCH_MONITOR=1371124518.12”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [s@macro-user-callerid:2] Set(“Local/200@from-queue-00000002;2”, “AMPUSER=”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [s@macro-user-callerid:3] GotoIf(“Local/200@from-queue-00000002;2”, “1?report”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Goto (macro-user-callerid,s,15)
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [s@macro-user-callerid:15] GotoIf(“Local/200@from-queue-00000002;2”, “0?continue”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [s@macro-user-callerid:16] Set(“Local/200@from-queue-00000002;2”, “__TTL=63”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [s@macro-user-callerid:17] GotoIf(“Local/200@from-queue-00000002;2”, “1?continue”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Goto (macro-user-callerid,s,28)
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [s@macro-user-callerid:28] Set(“Local/200@from-queue-00000002;2”, “CALLERID(number)=”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [s@macro-user-callerid:29] Set(“Local/200@from-queue-00000002;2”, “CALLERID(name)=External:”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [s@macro-user-callerid:30] Set(“Local/200@from-queue-00000002;2”, “CDR(cnum)=”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [s@macro-user-callerid:31] Set(“Local/200@from-queue-00000002;2”, “CDR(cnam)=External:”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [s@macro-user-callerid:32] Set(“Local/200@from-queue-00000002;2”, “CHANNEL(language)=en”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [s@macro-exten-vm:2] Set(“Local/200@from-queue-00000002;2”, “RingGroupMethod=none”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [s@macro-exten-vm:3] ExecIf(“Local/200@from-queue-00000002;2”, “1?Set(__ORIGEXTTOCALL=200)”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [s@macro-exten-vm:4] Set(“Local/200@from-queue-00000002;2”, “__EXTTOCALL=200”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [s@macro-exten-vm:5] Set(“Local/200@from-queue-00000002;2”, “__PICKUPMARK=200”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [s@macro-exten-vm:6] Set(“Local/200@from-queue-00000002;2”, “RT=15”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [s@macro-exten-vm:7] Gosub(“Local/200@from-queue-00000002;2”, “sub-record-check,s,1(exten,200,)”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [s@sub-record-check:1] Set(“Local/200@from-queue-00000002;2”, “REC_POLICY_MODE_SAVE=dontcare”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [s@sub-record-check:2] GotoIf(“Local/200@from-queue-00000002;2”, “1?check”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Goto (sub-record-check,s,7)
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [s@sub-record-check:7] Set(“Local/200@from-queue-00000002;2”, “__MON_FMT=wav”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [s@sub-record-check:8] GotoIf(“Local/200@from-queue-00000002;2”, “1?next”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Goto (sub-record-check,s,11)
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [s@sub-record-check:11] ExecIf(“Local/200@from-queue-00000002;2”, “0?Return()”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [s@sub-record-check:12] ExecIf(“Local/200@from-queue-00000002;2”, “0?Set(__REC_POLICY_MODE=)”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [s@sub-record-check:13] GotoIf(“Local/200@from-queue-00000002;2”, “1?exten,1”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Goto (sub-record-check,exten,1)
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [exten@sub-record-check:1] GotoIf(“Local/200@from-queue-00000002;2”, “1?callee”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Goto (sub-record-check,exten,8)
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [exten@sub-record-check:8] GosubIf(“Local/200@from-queue-00000002;2”, “0?record,1(exten,200,unknown)”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [exten@sub-record-check:9] Return(“Local/200@from-queue-00000002;2”, “”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [s@macro-exten-vm:8] GotoIf(“Local/200@from-queue-00000002;2”, “1?macrodial”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Goto (macro-exten-vm,s,14)
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [s@macro-exten-vm:14] GosubIf(“Local/200@from-queue-00000002;2”, “0?clrheader,1()”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [s@macro-exten-vm:15] Macro(“Local/200@from-queue-00000002;2”, “dial-one,15,TtrM(auto-blkvm),200”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [s@macro-dial-one:1] Set(“Local/200@from-queue-00000002;2”, “DEXTEN=200”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [s@macro-dial-one:2] Set(“Local/200@from-queue-00000002;2”, “DIALSTATUS_CW=”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [s@macro-dial-one:3] GosubIf(“Local/200@from-queue-00000002;2”, “0?screen,1()”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [s@macro-dial-one:4] GosubIf(“Local/200@from-queue-00000002;2”, “0?cf,1()”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [s@macro-dial-one:5] GotoIf(“Local/200@from-queue-00000002;2”, “1?skip1”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Goto (macro-dial-one,s,8)
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [s@macro-dial-one:8] GotoIf(“Local/200@from-queue-00000002;2”, “0?nodial”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [s@macro-dial-one:9] GotoIf(“Local/200@from-queue-00000002;2”, “0?continue”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [s@macro-dial-one:10] Set(“Local/200@from-queue-00000002;2”, “EXTHASCW=”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [s@macro-dial-one:11] GotoIf(“Local/200@from-queue-00000002;2”, “1?next1:cwinusebusy”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Goto (macro-dial-one,s,12)
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [s@macro-dial-one:12] GotoIf(“Local/200@from-queue-00000002;2”, “0?docfu:skip3”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Goto (macro-dial-one,s,16)
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [s@macro-dial-one:16] GotoIf(“Local/200@from-queue-00000002;2”, “1?next2:continue”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Goto (macro-dial-one,s,17)
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [s@macro-dial-one:17] GotoIf(“Local/200@from-queue-00000002;2”, “1?continue”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Goto (macro-dial-one,s,25)
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [s@macro-dial-one:25] GotoIf(“Local/200@from-queue-00000002;2”, “0?nodial”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [s@macro-dial-one:26] GosubIf(“Local/200@from-queue-00000002;2”, “1?dstring,1():dlocal,1()”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [dstring@macro-dial-one:1] Set(“Local/200@from-queue-00000002;2”, “DSTRING=”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [dstring@macro-dial-one:2] Set(“Local/200@from-queue-00000002;2”, “DEVICES=200”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [dstring@macro-dial-one:3] ExecIf(“Local/200@from-queue-00000002;2”, “0?Return()”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [dstring@macro-dial-one:4] ExecIf(“Local/200@from-queue-00000002;2”, “0?Set(DEVICES=00)”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [dstring@macro-dial-one:5] Set(“Local/200@from-queue-00000002;2”, “LOOPCNT=1”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [dstring@macro-dial-one:6] Set(“Local/200@from-queue-00000002;2”, “ITER=1”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [dstring@macro-dial-one:7] Set(“Local/200@from-queue-00000002;2”, “THISDIAL=SIP/200”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [dstring@macro-dial-one:8] GosubIf(“Local/200@from-queue-00000002;2”, “1?zap2dahdi,1()”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [zap2dahdi@macro-dial-one:1] ExecIf(“Local/200@from-queue-00000002;2”, “0?Return()”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [zap2dahdi@macro-dial-one:2] Set(“Local/200@from-queue-00000002;2”, “NEWDIAL=”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [zap2dahdi@macro-dial-one:3] Set(“Local/200@from-queue-00000002;2”, “LOOPCNT2=1”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [zap2dahdi@macro-dial-one:4] Set(“Local/200@from-queue-00000002;2”, “ITER2=1”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [zap2dahdi@macro-dial-one:5] Set(“Local/200@from-queue-00000002;2”, “THISPART2=SIP/200”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [zap2dahdi@macro-dial-one:6] ExecIf(“Local/200@from-queue-00000002;2”, “0?Set(THISPART2=DAHDI/200)”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [zap2dahdi@macro-dial-one:7] Set(“Local/200@from-queue-00000002;2”, “NEWDIAL=SIP/200&”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [zap2dahdi@macro-dial-one:8] Set(“Local/200@from-queue-00000002;2”, “ITER2=2”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [zap2dahdi@macro-dial-one:9] GotoIf(“Local/200@from-queue-00000002;2”, “0?begin2”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [zap2dahdi@macro-dial-one:10] Set(“Local/200@from-queue-00000002;2”, “THISDIAL=SIP/200”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [zap2dahdi@macro-dial-one:11] Return(“Local/200@from-queue-00000002;2”, “”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [dstring@macro-dial-one:9] Set(“Local/200@from-queue-00000002;2”, “DSTRING=SIP/200&”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [dstring@macro-dial-one:10] Set(“Local/200@from-queue-00000002;2”, “ITER=2”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [dstring@macro-dial-one:11] GotoIf(“Local/200@from-queue-00000002;2”, “0?begin”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [dstring@macro-dial-one:12] Set(“Local/200@from-queue-00000002;2”, “DSTRING=SIP/200”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [dstring@macro-dial-one:13] Return(“Local/200@from-queue-00000002;2”, “”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [s@macro-dial-one:27] GotoIf(“Local/200@from-queue-00000002;2”, “0?nodial”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [s@macro-dial-one:28] GotoIf(“Local/200@from-queue-00000002;2”, “0?skiptrace”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [s@macro-dial-one:29] GosubIf(“Local/200@from-queue-00000002;2”, “0?ctset,1():ctclear,1()”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [ctclear@macro-dial-one:1] NoOp(“Local/200@from-queue-00000002;2”, "Deleting: CALLTRACE/200 ") in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [ctclear@macro-dial-one:2] Return(“Local/200@from-queue-00000002;2”, “”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [s@macro-dial-one:30] Set(“Local/200@from-queue-00000002;2”, “D_OPTIONS=TtrM(auto-blkvm)”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [s@macro-dial-one:31] ExecIf(“Local/200@from-queue-00000002;2”, “0?SIPAddHeader(Alert-Info: )”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [s@macro-dial-one:32] ExecIf(“Local/200@from-queue-00000002;2”, “0?SIPAddHeader()”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [s@macro-dial-one:33] ExecIf(“Local/200@from-queue-00000002;2”, “1?Set(CHANNEL(musicclass)=default)”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [s@macro-dial-one:34] GosubIf(“Local/200@from-queue-00000002;2”, “0?qwait,1()”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [s@macro-dial-one:35] Set(“Local/200@from-queue-00000002;2”, “__CWIGNORE=TRUE”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [s@macro-dial-one:36] Set(“Local/200@from-queue-00000002;2”, “__KEEPCID=TRUE”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [s@macro-dial-one:37] GotoIf(“Local/200@from-queue-00000002;2”, “0?usegoto,1”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [s@macro-dial-one:38] GotoIf(“Local/200@from-queue-00000002;2”, “1?godial”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Goto (macro-dial-one,s,42)
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] pbx.c: – Executing [s@macro-dial-one:42] Dial(“Local/200@from-queue-00000002;2”, “SIP/200,15,TtrM(auto-blkvm)”) in new stack
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] netsock2.c: == Using SIP RTP TOS bits 184
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] netsock2.c: == Using SIP RTP CoS mark 5
[2013-06-13 12:55:18] VERBOSE[4371][C-00000003] app_dial.c: – Called SIP/200
[2013-06-13 12:55:18] VERBOSE[4356][C-00000003] app_queue.c: – Local/200@from-queue-00000002;1 is ringing
[2013-06-13 12:55:19] VERBOSE[4371][C-00000003] app_dial.c: – SIP/200-00000004 is ringing
[2013-06-13 12:55:19] VERBOSE[4356][C-00000003] app_queue.c: – Local/200@from-queue-00000002;1 is ringing

Thanks in advance!

Hi,
I am also based in the UK and have been using various flavours of Asterisk for many years. Now settled on FreePBX / Asterisk 11 using BRI & SIP
This may sound silly but have you spoken to BT and asked them if Caller ID is enabled on your POTs line. By default it is disabled as it’s a chargeable service.

Are you using caller ID as in inbound service or outbound ? To test inbound is simple, create an entry in the FreePBX phonebook with your mobile number and name. Set Phonebook up as a directory lookup source. Add the source to the inbound route. If your extension displays your name, inbound CID is working. Outbound is just as simple. ring your mobile and see if the number appears.

Two things to bear in mind. When sending a number you can ONLY send the number the line owns. i.e. if you set your trunk to send 999 as your CID on your POTs line it will not work and will display unknown on your mobile.

If you set you’re extension to send your DDI when calling outbound in the Outbound CID section the number has to be encapsulated in <>… as per the hover over hint.

Obviously all this is dependant on the trunk for the POTs line working properly and at least allowing you to make calls from it :slight_smile:

Ta
Pigsfoot

Thought I best add chan_dahdi.conf

[general]

; generated by module
#include chan_dahdi_general.conf

; for user additions not provided by module
#include chan_dahdi_general_custom.conf

[channels]
language=en
busydetect=yes
busycount=3
usecallerid=yes
callwaiting=yes
usecallingpres=yes
threewaycalling=yes
transfer=yes
cancallforward=yes
callreturn=yes
echocancel=yes
echocancelwhenbridged=no
echotraining=no
immediate=yes
faxdetect=no
rxgain=8.0
txgain=5.0
ukcallerid=yes
ringtimeout=8000
cidsignalling=v23
cidstart=polarity
signalling=fxs_ks
callerid=asreceived
hanguponpolarityswitch=yes
callprogress=yes
sendcalleridafter=1
rxwink=300
hidecallerid=no
canpark=yes
progzone=uk

; for user additions not provided by module
#include chan_dahdi_channels_custom.conf

; include dahdi groups defined by DAHDI module of FreePBX
#include chan_dahdi_groups.conf

; include dahdi extensions defined in FreePBX
#include chan_dahdi_additional.conf

and /etc/modprobe.d/dahdi.conf

options wctdm opermode=UK fwringdetect=1 battthresh=4

And I think thats it. The system.conf sets the Tone to UK and enables the software echo canceller.

Any other info I can provide let me know.
Any other info you can provide, I’ll kiss your feet.

Moo

Hey Pigsfoot, thanks for the reply!

I should have mentioned that this is inbound only. Outbound CLI works fine.

Hold on a minute. It is the simple things isn’t it?

While writing this, I plugged in an analog handset and tried the number, NO CALLER ID!!

I also tried dialing ‘#234#’ (and ‘*234#’) which told me the service is not available. So it stands to reason, that this line doesn’t have it!!

What a muppet! Anyway, thanks again and I have plenty more questions coming…

Moo

Ha Ha… no worries… we have all been there… well I have anyway and it’s only from these forums and help from others that you finally get to resolve issues… even if you work it out yourself.

I work for a POTS provider, and was thinking about halfway through your first post, “You know I wonder if BT is sending CID at all over that line…”

Pigsfoot is exactly right. Probably every user in the forums has learned a great deal from the charity of others- or by typing out the problem and figuring it out themselves!