How do I troubleshoot CallerID and lookup sources?

I cannot get CallerID to work. Here is my configuration:

PBX in a Flash 1.4
Asterisk 1.6 using DAHDI
Sangoma A101 PRI card
MySQL as the caller ID source.

In my previous test system, which used a generic FXO card, CallerID worked flawlessly.

I would really like to find a troubleshooting methodology, but a solution would be fine, too.

Thanks.

Have you looked at a call coming in via the CLI to see what is being given to you. If you are not configured properly on the PRI it is possible that you are not getting the CID info, also check that your provider is giving it to you, they might not be.

I cannot interpret the results, however. Below is what I saw. Any help would be appreciated. Thanks.

-- Accepting call from '5556001' to '5551234' on channel 0/16, span 1
-- Executing [5551234@from-pstn:1] Set("DAHDI/16-1", "__FROM_DID=5551234") in new stack
-- Executing [5551234@from-pstn:2] Gosub("DAHDI/16-1", "cidlookup,cidlookup_1,1") in new stack
-- Executing [cidlookup_1@cidlookup:1] MYSQL("DAHDI/16-1", "Connect connid localhost xxxxx xxxxxxx cidlookup") in new stack
-- Executing [cidlookup_1@cidlookup:2] MYSQL("DAHDI/16-1", "Query resultid 1 SELECT\ CONCAT\(name\,\'\,\ \'\,phonetype\,\'\,\ \'\,pacts_id\)\ from\ callerid\ WHERE\ number\ LIKE\ \'%5556001%\'") in new stack
-- Executing [cidlookup_1@cidlookup:3] MYSQL("DAHDI/16-1", "Fetch fetchid  CALLERID(name)") in new stack
-- Executing [cidlookup_1@cidlookup:4] MYSQL("DAHDI/16-1", "Clear ") in new stack
-- Executing [cidlookup_1@cidlookup:5] MYSQL("DAHDI/16-1", "Disconnect 1") in new stack
-- Executing [cidlookup_1@cidlookup:6] Return("DAHDI/16-1", "") in new stack
-- Executing [5551234@from-pstn:3] ExecIf("DAHDI/16-1", "1 ?Set(CALLERID(name)=5556001)") in new stack
-- Executing [5551234@from-pstn:4] Set("DAHDI/16-1", "__CALLINGPRES_SV=allowed_not_screened") in new stack
-- Executing [5551234@from-pstn:5] Set("DAHDI/16-1", "CALLERPRES()=allowed_not_screened") in new stack
-- Executing [5551234@from-pstn:6] Goto("DAHDI/16-1", "from-did-direct,1234,1") in new stack
-- Goto (from-did-direct,1234,1)
-- Executing [1234@from-did-direct:1] Macro("DAHDI/16-1", "exten-vm,novm,1234") in new stack
-- Executing [s@macro-exten-vm:1] Macro("DAHDI/16-1", "user-callerid") in new stack
-- Executing [s@macro-user-callerid:1] Set("DAHDI/16-1", "AMPUSER=5556001") in new stack
-- Executing [s@macro-user-callerid:2] GotoIf("DAHDI/16-1", "0?report") in new stack
-- Executing [s@macro-user-callerid:3] ExecIf("DAHDI/16-1", "1?Set(REALCALLERIDNUM=5556001)") in new stack
-- Executing [s@macro-user-callerid:4] Set("DAHDI/16-1", "AMPUSER=") in new stack
-- Executing [s@macro-user-callerid:5] Set("DAHDI/16-1", "AMPUSERCIDNAME=") in new stack
-- Executing [s@macro-user-callerid:6] GotoIf("DAHDI/16-1", "1?report") in new stack
-- Goto (macro-user-callerid,s,10)
-- Executing [s@macro-user-callerid:10] GotoIf("DAHDI/16-1", "0?continue") in new stack
-- Executing [s@macro-user-callerid:11] Set("DAHDI/16-1", "__TTL=64") in new stack
-- Executing [s@macro-user-callerid:12] GotoIf("DAHDI/16-1", "1?continue") in new stack
-- Goto (macro-user-callerid,s,19)
-- Executing [s@macro-user-callerid:19] NoOp("DAHDI/16-1", "Using CallerID "5556001" <5556001>") in new stack
-- Executing [s@macro-exten-vm:2] Set("DAHDI/16-1", "RingGroupMethod=none") in new stack
-- Executing [s@macro-exten-vm:3] Set("DAHDI/16-1", "VMBOX=novm") in new stack
-- Executing [s@macro-exten-vm:4] Set("DAHDI/16-1", "EXTTOCALL=1234") in new stack
-- Executing [s@macro-exten-vm:5] Set("DAHDI/16-1", "CFUEXT=") in new stack
-- Executing [s@macro-exten-vm:6] Set("DAHDI/16-1", "CFBEXT=") in new stack
-- Executing [s@macro-exten-vm:7] Set("DAHDI/16-1", "RT=""") in new stack
-- Executing [s@macro-exten-vm:8] Macro("DAHDI/16-1", "record-enable,1234,IN") in new stack
-- Executing [s@macro-record-enable:1] GotoIf("DAHDI/16-1", "1?check") in new stack
-- Goto (macro-record-enable,s,4)
-- Executing [s@macro-record-enable:4] AGI("DAHDI/16-1", "recordingcheck,20090422-133305,1240432385.57") in new stack
-- Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck

recordingcheck,20090422-133305,1240432385.57: Inbound recording not enabled
– <DAHDI/16-1>AGI Script recordingcheck completed, returning 0
– Executing [s@macro-record-enable:5] MacroExit(“DAHDI/16-1”, “”) in new stack
– Executing [s@macro-exten-vm:9] Macro(“DAHDI/16-1”, “dial,tr,1234”) in new stack
– Executing [s@macro-dial:1] GotoIf(“DAHDI/16-1”, “1?dial”) in new stack
– Goto (macro-dial,s,3)
– Executing [s@macro-dial:3] AGI(“DAHDI/16-1”, “dialparties.agi”) in new stack
– Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
dialparties.agi: Starting New Dialparties.agi
== Manager ‘admin’ logged on from 127.0.0.1
dialparties.agi: Caller ID name is ‘5556001’ number is '5556001’
dialparties.agi: Methodology of ring is ‘none’
– dialparties.agi: Added extension 1234 to extension map
– dialparties.agi: Extension 1234 cf is disabled
– dialparties.agi: Extension 1234 do not disturb is disabled
– dialparties.agi: dbset CALLTRACE/1234 to 5556001
– dialparties.agi: Filtered ARG3: 1234
== Manager ‘admin’ logged off from 127.0.0.1
– <DAHDI/16-1>AGI Script dialparties.agi completed, returning 0
– Executing [s@macro-dial:7] Dial(“DAHDI/16-1”, “SIP/1234,tr”) in new stack
== Using SIP RTP TOS bits 184
== Using SIP RTP CoS mark 5
== Extension Changed 1234[ext-local] new state Ringing for Notify User 1200
– Called 1234
– SIP/1234-08f7fd70 is ringing
– Channel 0/16, span 1 got hangup request, cause 16
== Spawn extension (macro-dial, s, 7) exited non-zero on ‘DAHDI/16-1’ in macro ‘dial’
== Spawn extension (macro-exten-vm, s, 9) exited non-zero on ‘DAHDI/16-1’ in macro ‘exten-vm’
== Spawn extension (from-did-direct, 1234, 1) exited non-zero on ‘DAHDI/16-1’
== Extension Changed 1234[ext-local] new state Idle for Notify User 1200
– Hungup ‘DAHDI/16-1’

by the switch correctly, and it also looks like the database query is being executed. I don’t really know enough to interpret what is happening after that.

One difference between this system and my earlier system is the earlier (working) system uses Zaptel and this one uses DAHDI.

…which uses Asterisk 1.4 with zaptel and FXO instead of PRI. The messages are significantly different.

Connected to Asterisk 1.4.21.2 currently running on orp-testpbx (pid = 3364)
Verbosity is at least 3
– 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@macro-from-zaptel-2:1] NoOp(“Zap/2-1”, “Entering macro-from-zaptel-2 with DID = s and setting to: 5033262064”) in new stack
– Executing [s@macro-from-zaptel-2:2] Set(“Zap/2-1”, “__FROM_DID=5033262064”) in new stack
– Executing [s@macro-from-zaptel-2:3] Goto(“Zap/2-1”, “from-trunk|5033262064|1”) in new stack
– Goto (from-trunk,5033262064,1)
== Channel ‘Zap/2-1’ jumping out of macro ‘from-zaptel-2’
– Executing [5033262064@from-trunk:1] Set(“Zap/2-1”, “__FROM_DID=5033262064”) in new stack
– Executing [5033262064@from-trunk:2] Gosub(“Zap/2-1”, “cidlookup|cidlookup_1|1”) in new stack
– Executing [cidlookup_1@cidlookup:1] MYSQL(“Zap/2-1”, “Connect connid localhost xxxx xxxxxxx cidlookup”) in new stack
– Executing [cidlookup_1@cidlookup:2] MYSQL(“Zap/2-1”, “Query resultid 1 SELECT CONCAT(name,’, ‘,phonetype,’, ',pacts_id) from callerid WHERE number LIKE ‘%%’”) in new stack
– Executing [cidlookup_1@cidlookup:3] MYSQL(“Zap/2-1”, “Fetch fetchid 2 CALLERID(name)”) in new stack
– Executing [cidlookup_1@cidlookup:4] MYSQL(“Zap/2-1”, “Clear 2”) in new stack
– Executing [cidlookup_1@cidlookup:5] MYSQL(“Zap/2-1”, “Disconnect 1”) in new stack
– Executing [cidlookup_1@cidlookup:6] Return(“Zap/2-1”, “”) in new stack
– Executing [5033262064@from-trunk:3] ExecIf(“Zap/2-1”, “0 |Set|CALLERID(name)=”) in new stack
– Executing [5033262064@from-trunk:4] Set(“Zap/2-1”, “FAX_RX=disabled”) in new stack
– Executing [5033262064@from-trunk:5] Set(“Zap/2-1”, “__CALLINGPRES_SV=allowed_not_screened”) in new stack
– Executing [5033262064@from-trunk:6] SetCallerPres(“Zap/2-1”, “allowed_not_screened”) in new stack
– Executing [5033262064@from-trunk:7] Goto(“Zap/2-1”, “ext-group|600|1”) in new stack
– Goto (ext-group,600,1)
– Executing [600@ext-group:1] Macro(“Zap/2-1”, “user-callerid|”) in new stack
– Executing [s@macro-user-callerid:1] Set(“Zap/2-1”, “AMPUSER=”) in new stack
– Executing [s@macro-user-callerid:2] GotoIf(“Zap/2-1”, “0?report”) in new stack
– Executing [s@macro-user-callerid:3] ExecIf(“Zap/2-1”, “1|Set|REALCALLERIDNUM=”) in new stack
– Executing [s@macro-user-callerid:4] Set(“Zap/2-1”, “AMPUSER=”) in new stack
– Executing [s@macro-user-callerid:5] Set(“Zap/2-1”, “AMPUSERCIDNAME=”) in new stack
– Executing [s@macro-user-callerid:6] GotoIf(“Zap/2-1”, “1?report”) in new stack
– Goto (macro-user-callerid,s,10)
– Executing [s@macro-user-callerid:10] GotoIf(“Zap/2-1”, “0?continue”) in new stack
– Executing [s@macro-user-callerid:11] Set(“Zap/2-1”, “__TTL=64”) in new stack
– Executing [s@macro-user-callerid:12] GotoIf(“Zap/2-1”, “1?continue”) in new stack
– Goto (macro-user-callerid,s,19)
– Executing [s@macro-user-callerid:19] NoOp(“Zap/2-1”, “Using CallerID “Corrigan, Patrick, H, 67295” <>”) in new stack
– Executing [600@ext-group:2] GotoIf(“Zap/2-1”, “1?skipdb”) in new stack
– Goto (ext-group,600,4)
– Executing [600@ext-group:4] Set(“Zap/2-1”, “__NODEST=”) in new stack
– Executing [600@ext-group:5] Set(“Zap/2-1”, “__BLKVM_OVERRIDE=BLKVM/600/Zap/2-1”) in new stack
– Executing [600@ext-group:6] Set(“Zap/2-1”, “__BLKVM_BASE=600”) in new stack
– Executing [600@ext-group:7] Set(“Zap/2-1”, “DB(BLKVM/600/Zap/2-1)=TRUE”) in new stack
– Executing [600@ext-group:8] Set(“Zap/2-1”, “RRNODEST=”) in new stack
– Executing [600@ext-group:9] Set(“Zap/2-1”, “__NODEST=600”) in new stack
– Executing [600@ext-group:10] Set(“Zap/2-1”, “RecordMethod=Group”) in new stack
– Executing [600@ext-group:11] Macro(“Zap/2-1”, “record-enable|1000-1001-1005|Group”) in new stack
– Executing [s@macro-record-enable:1] GotoIf(“Zap/2-1”, “1?check”) in new stack
– Goto (macro-record-enable,s,4)
– Executing [s@macro-record-enable:4] AGI(“Zap/2-1”, “recordingcheck|20090422-142306|1240435381.57”) in new stack
– Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
– AGI Script recordingcheck completed, returning 0
– Executing [s@macro-record-enable:5] MacroExit(“Zap/2-1”, “”) in new stack
– Executing [600@ext-group:12] Set(“Zap/2-1”, “RingGroupMethod=ringall”) in new stack
– Executing [600@ext-group:13] Macro(“Zap/2-1”, “dial|20|tr|1000-1001-1005”) 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_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 ‘Corrigan, Patrick, H, 67295’ number is 'unknown’
dialparties.agi: Methodology of ring is ‘ringall’
– dialparties.agi: Added extension 1000 to extension map
– dialparties.agi: Added extension 1001 to extension map
– dialparties.agi: Added extension 1005 to extension map
– dialparties.agi: Extension 1000 cf is disabled
– dialparties.agi: Extension 1001 cf is disabled
– dialparties.agi: Extension 1005 cf is disabled
– dialparties.agi: Extension 1000 do not disturb is disabled
– dialparties.agi: Extension 1001 do not disturb is disabled
– dialparties.agi: Extension 1005 do not disturb is disabled
– dialparties.agi: DbDel CALLTRACE/1000 - Caller ID is not defined
– dialparties.agi: DbDel CALLTRACE/1001 - Caller ID is not defined
– dialparties.agi: DbDel CALLTRACE/1005 - Caller ID is not defined
– dialparties.agi: Filtered ARG3: 1000-1001-1005
== 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/1000&SIP/1001&SIP/1005|20|trM(auto-blkvm)”) in new stack
– Called 1005
– SIP/1005-08235778 is ringing