CID with openCNAM cache not working

volkswagner · August 15, 2020, 11:08pm

Greetings,

I was trying to find more information about the cache function when using caller id lookups
via OpenCNAM.

The wiki seems a bit dated, so I’m not sure if it’s still relevant.

I thought enabling cache would “automagically” store results and then flush after a certain number of days. The help hint for cache says “Decide whether or not cache the results to astDB; it will overwrite present values. It does not affect Internal source behavior”. This is what led me to believe there was
some built-in function to add results to the database, then clean up at some interval.

It seems this is not true. How to I prevent the same calling numbers from getting queried every time?

Some reading seemed to indicate perhaps manually adding numbers/names to the internal phonebook would act as a cache.

Can anyone help explain or point me to more detailed docs?

I’m running distro FreePBX 14.0.13.34.

Cheers!

Stewart1 · August 15, 2020, 11:36pm

I don’t know the answer to your question, but on my system Cache Results is turned on, lookups get cached and on a cache hit the cached result is used and no lookup is done. However, there is no automatic purge and AFAIK none was ever implemented.

Because my system is small, I don’t worry about that. If a friend or customer changes their number, it’s very unlikely that I will ever get a call from the new owner of that number; the stale cache would not be an issue.

You can view Admin -> Asterisk Phonebook to see whether your lookups are getting cached. If not, post a log of an incoming call and maybe we can see why not. If lookups are being cached but a ‘hit’ still results in a gratuitous lookup, post a log of such a call.

volkswagner · August 16, 2020, 12:37am

@Stewart1,

Thanks for pointing to the cached info menu.
How odd I’ve never been on that screen.

I’ll perform those diagnostic tasks, and report back
on the gratuitous lookups.

I saw numbers saved in the phonebook that are regularly looked up via OpenCNAME.

volkswagner · August 16, 2020, 2:50pm

I’m not sure if you need pjsip debug on and if pulling from logs is sufficient.

Here are two successive inbound lookups. This number should have been cached even before
the first lookup.

first call:
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:3] Return("PJSIP/MainRouteIn-00000c92", "") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:5] Return("PJSIP/MainRouteIn-00000c92", "") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:3] Set("PJSIP/MainRouteIn-00000c92", "CHANNEL(tonezone)=us") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:4] Set("PJSIP/MainRouteIn-00000c92", "__FROM_DID=1xxxxxx1978") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:5] Set("PJSIP/MainRouteIn-00000c92", "returnhere=1") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:6] Gosub("PJSIP/MainRouteIn-00000c92", "app-blacklist-check,s,1()") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:1] GotoIf("PJSIP/MainRouteIn-00000c92", "0?blacklisted") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:2] Set("PJSIP/MainRouteIn-00000c92", "CALLED_BLACKLIST=1") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:3] Return("PJSIP/MainRouteIn-00000c92", "") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:7] Set("PJSIP/MainRouteIn-00000c92", "CDR(did)=1xxxxxx1978") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:8] GotoIf("PJSIP/MainRouteIn-00000c92", "0?") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:9] ExecIf("PJSIP/MainRouteIn-00000c92", "0 ?Set(CALLERID(name)=1xxxxxx7359)") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:10] Set("PJSIP/MainRouteIn-00000c92", "CHANNEL(musicclass)=stream-70s") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:11] Set("PJSIP/MainRouteIn-00000c92", "__MOHCLASS=stream-70s") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:12] Set("PJSIP/MainRouteIn-00000c92", "__REVERSAL_REJECT=FALSE") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:13] GotoIf("PJSIP/MainRouteIn-00000c92", "1?post-reverse-charge") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx_builtins.c: Goto (from-pstn,1xxxxxx1978,15)
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:15] NoOp("PJSIP/MainRouteIn-00000c92", "") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:16] Set("PJSIP/MainRouteIn-00000c92", "__CALLINGNAMEPRES_SV=allowed_not_screened") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:17] Set("PJSIP/MainRouteIn-00000c92", "__CALLINGNUMPRES_SV=allowed_not_screened") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:18] Set("PJSIP/MainRouteIn-00000c92", "CALLERID(name-pres)=allowed_not_screened") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:19] Set("PJSIP/MainRouteIn-00000c92", "CALLERID(num-pres)=allowed_not_screened") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:20] Gosub("PJSIP/MainRouteIn-00000c92", "cidlookup,cidlookup_1,1()") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:1] Set("PJSIP/MainRouteIn-00000c92", "CURLOPT(httptimeout)=7") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:2] Set("PJSIP/MainRouteIn-00000c92", "CALLERID(name)=MR ZERVA") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:3] Set("PJSIP/MainRouteIn-00000c92", "DB(cidname/1xxxxxx7359)=MR ZERVA") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:4] Return("PJSIP/MainRouteIn-00000c92", "") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:21] NoOp("PJSIP/MainRouteIn-00000c92", "CallerID Entry Point") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:22] Goto("PJSIP/MainRouteIn-00000c92", "from-did-direct,206,1") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx_builtins.c: Goto (from-did-direct,206,1)


second call:
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:5] Return("PJSIP/MainRouteIn-00000c92", "") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:3] Set("PJSIP/MainRouteIn-00000c92", "CHANNEL(tonezone)=us") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:4] Set("PJSIP/MainRouteIn-00000c92", "__FROM_DID=1xxxxxx1978") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:5] Set("PJSIP/MainRouteIn-00000c92", "returnhere=1") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:6] Gosub("PJSIP/MainRouteIn-00000c92", "app-blacklist-check,s,1()") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:1] GotoIf("PJSIP/MainRouteIn-00000c92", "0?blacklisted") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:2] Set("PJSIP/MainRouteIn-00000c92", "CALLED_BLACKLIST=1") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:3] Return("PJSIP/MainRouteIn-00000c92", "") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:7] Set("PJSIP/MainRouteIn-00000c92", "CDR(did)=1xxxxxx1978") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:8] GotoIf("PJSIP/MainRouteIn-00000c92", "0?") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:9] ExecIf("PJSIP/MainRouteIn-00000c92", "0 ?Set(CALLERID(name)=1xxxxxx7359)") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:10] Set("PJSIP/MainRouteIn-00000c92", "CHANNEL(musicclass)=stream-70s") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:11] Set("PJSIP/MainRouteIn-00000c92", "__MOHCLASS=stream-70s") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:12] Set("PJSIP/MainRouteIn-00000c92", "__REVERSAL_REJECT=FALSE") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:13] GotoIf("PJSIP/MainRouteIn-00000c92", "1?post-reverse-charge") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx_builtins.c: Goto (from-pstn,1xxxxxx1978,15)
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:15] NoOp("PJSIP/MainRouteIn-00000c92", "") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:16] Set("PJSIP/MainRouteIn-00000c92", "__CALLINGNAMEPRES_SV=allowed_not_screened") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:17] Set("PJSIP/MainRouteIn-00000c92", "__CALLINGNUMPRES_SV=allowed_not_screened") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:18] Set("PJSIP/MainRouteIn-00000c92", "CALLERID(name-pres)=allowed_not_screened") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:19] Set("PJSIP/MainRouteIn-00000c92", "CALLERID(num-pres)=allowed_not_screened") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:20] Gosub("PJSIP/MainRouteIn-00000c92", "cidlookup,cidlookup_1,1()") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:1] Set("PJSIP/MainRouteIn-00000c92", "CURLOPT(httptimeout)=7") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:2] Set("PJSIP/MainRouteIn-00000c92", "CALLERID(name)=MR ZERVA") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:3] Set("PJSIP/MainRouteIn-00000c92", "DB(cidname/1xxxxxx7359)=MR ZERVA") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:4] Return("PJSIP/MainRouteIn-00000c92", "") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:21] NoOp("PJSIP/MainRouteIn-00000c92", "CallerID Entry Point") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:22] Goto("PJSIP/MainRouteIn-00000c92", "from-did-direct,206,1") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx_builtins.c: Goto (from-did-direct,206,1)
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:1] GotoIf("PJSIP/MainRouteIn-00000c92", "1?ext-local,206,1:followme-check,206,1") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx_builtins.c: Goto (ext-local,206,1)
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:1] Set("PJSIP/MainRouteIn-00000c92", "__RINGTIMER=15") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:2] ExecIf("PJSIP/MainRouteIn-00000c92", "0?Set(__CWIGNORE=)") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:3] Macro("PJSIP/MainRouteIn-00000c92", "exten-vm,206,206,0,0,0") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:1] Macro("PJSIP/MainRouteIn-00000c92", "user-callerid,") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:1] Set("PJSIP/MainRouteIn-00000c92", "TOUCH_MONITOR=1597441091.11115") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:2] Set("PJSIP/MainRouteIn-00000c92", "AMPUSER=1xxxxxx7359") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:3] Set("PJSIP/MainRouteIn-00000c92", "HOTDESCKCHAN=MainRouteIn-00000c92") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:4] Set("PJSIP/MainRouteIn-00000c92", "HOTDESKEXTEN=MainRouteIn") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:5] Set("PJSIP/MainRouteIn-00000c92", "HOTDESKCALL=0") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:6] ExecIf("PJSIP/MainRouteIn-00000c92", "0?Set(HOTDESKCALL=1)") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:7] ExecIf("PJSIP/MainRouteIn-00000c92", "0?Set(CALLERID(name)=)") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]ro-user-callerid:8] GotoIf("PJSIP/MainRouteIn-00000c92", "0?report") in new stack
[2020-08-14 21:38:11] VERBOSE[25398][C-0000052c] pbx.c: Executing [[email protected]:9] ExecIf("PJSIP/MainRouteIn-00000c92", "1?Set(REALCALLERIDNUM=1xxxxxx7359)") in new stack

Both calls show up in OpenCNAM report as charged lookups.

I’m seeing this symptom across multiple servers (all on the same version). I think it started several months ago (perhaps after some updates).

volkswagner · August 21, 2020, 12:47am

Bump.

Does anyone know how to further troubleshoot?

How do I determine why the internal database isn’t queried or
results are not found?

Stewart1 · August 21, 2020, 2:44am

Sorry, I didn’t realize on my earlier posts that I had customized the relevant code. The purpose was to utilize SignalWire lookups, which are returned in a JSON format that FreePBX can’t natively parse. Also, the trunking provider returns a name on some calls, so I don’t look them up either. It’s possible that the overridden code doesn’t cache properly. Here is my version:

[cidlookup]
exten => cidlookup_1,1,GotoIf($["${CALLERID(name)}" = ""]?continue)
exten => cidlookup_1,n,GotoIf($["${CALLERID(name):0:1}" != "+"]?nameok)
exten => cidlookup_1,n(continue),GotoIf($[${DB_EXISTS(cidname/${CALLERID(num)})} = 1]?cidlookup,cidlookup_return,1)
exten => cidlookup_1,n,Set(CURLOPT(httptimeout)=5)
exten => cidlookup_1,n,Set(cnamjson=${CURL(https://myusername:[email protected]:443//api/relay/rest/lookup/phone_number/+1${CALLERID(num)}?include=cnam)})
exten => cidlookup_1,n,NoOp(cnamjson=${cnamjson})
exten => cidlookup_1,n,Set(cnamjson=${CUT(cnamjson,\{,3)})
exten => cidlookup_1,n,NoOp(cnamjson=${cnamjson})
exten => cidlookup_1,n,Set(CALLERID(name)=${CUT(cnamjson,\",4)})
exten => cidlookup_1,n,NoOp(name=${CALLERID(name)})
exten => cidlookup_1,n,Set(DB(cidname/${CALLERID(num)})=${CALLERID(name)})
exten => cidlookup_1,n(nameok),Return()

exten => cidlookup_return,1,ExecIf($["${DB(cidname/${CALLERID(num)})}" != ""]?Set(CALLERID(name)=${DB(cidname/${CALLERID(num)})}))
exten => cidlookup_return,n,Return()

;--== end of [cidlookup] ==--;

The basic flow: If the name from the provider is not null and doesn’t begin with +, I assume that’s a good name and use it. Otherwise, if it’s in the cache I use that. Otherwise, I make the API call, extract the name from the JSON, put it in the cache and use it.

lgaetz · August 21, 2020, 11:51am

From what I can tell, there is (and never was) an option in the CID Lookup module to check the cache prior to doing the lookup. This can be done with CID Superfecta, where you can define multiple source, and order the cache before the others.

volkswagner · August 21, 2020, 12:12pm

That’s very interesting. Perhaps the misleading option “use cache” should be
removed, or the help hint should be updated to say something like “custom code
required to make this work”.

volkswagner · August 22, 2020, 2:07am

@Stewart1
Would you mind teaching me where to customize this?
I checked /etc/asterisk/extensions_additional.conf and found:

[cidlookup]
include => cidlookup-custom
exten => cidlookup_1,1,Set(CURLOPT(httptimeout)=7)
exten => cidlookup_1,n,Set(CALLERID(name)=${CURL(https://username:[email protected]/v2/phone/${CALLERID(num)}?format=pbx&ref=freepbx)})
exten => cidlookup_1,n,Set(DB(cidname/${CALLERID(num)})=${CALLERID(name)})
exten => cidlookup_1,n,Return()
exten => cidlookup_return,1,ExecIf($["${DB(cidname/${CALLERID(num)})}" != ""]?Set(CALLERID(name)=${DB(cidname/${CALLERID(num)})}))
exten => cidlookup_return,n,Return()

;--== end of [cidlookup] ==--;

But this file says not to edit directly. Should create a file called cidlookup-custom (as indicated in the include statement) or simply
backup extensions_additional.conf, make edits, then also create a backup of my new file so
I can restore it when updates overwrite the extensions_additional.conf?

I’m thinking I simply need to add your one-liner between the include statement and httptimeout.

exten => cidlookup_1,n(continue),GotoIf($[${DB_EXISTS(cidname/${CALLERID(num)})} = 1]?cidlookup,cidlookup_return,1)

If I’m supposed to add it to a file called “cidlookup-custom”, I don’t know what magic I need to
include so it get’s put into the sequence prior to openCnam lookup.

I added your one-liner as described, but
I get the same result (cid is still queried to OpenCNAM and not pulled from Asterisk DB). I think
this is because fwconsole reload kills my edit.

Stewart1 · August 22, 2020, 4:13am

The file should go in
/etc/asterisk/extensions_override_freepbx.conf
and then do
fwconsole reload

volkswagner · August 22, 2020, 10:50am

Thanks @Stewart1, Do I need to remove my callerID source from the
inbound routes in FreePBX GUI? I add the following to /etc/asterisk/extensions_override_freepbx.conf, but lookups still go to OpenCNAM. I assume because the settings are still in extensions_additional.conf.

[cidlookup]
include => cidlookup-custom
exten => cidlookup_1,n(continue),GotoIf($[${DB_EXISTS(cidname/${CALLERID(num)})} = 1]?cidlookup,cidlookup_return,1)
exten => cidlookup_1,1,Set(CURLOPT(httptimeout)=7)
exten => cidlookup_1,n,Set(CALLERID(name)=${CURL(https://username:[email protected]/v2/phone/${CALLERID(num)}?format=pbx&ref=freepbx)})
exten => cidlookup_1,n,Set(DB(cidname/${CALLERID(num)})=${CALLERID(name)})
exten => cidlookup_1,n,Return()

exten => cidlookup_return,1,ExecIf($["${DB(cidname/${CALLERID(num)})}" != ""]?Set(CALLERID(name)=${DB(cidname/${CALLERID(num)})}))
exten => cidlookup_return,n,Return()

;--== end of [cidlookup] ==--;

Stewart1 · August 22, 2020, 2:45pm

No, your code is overriding the what the Inbound Route calls. Does the log show it being executed? If so, is the DB being written? Being accessed on subsequent calls?

Stewart1 · August 22, 2020, 2:58pm

Also, look at your extensions_additional.conf for cidlookup_2, cidlookup_3, etc.

volkswagner · August 23, 2020, 4:15am

The only mention of ‘cid’ in extensions_additional, are what I posted earlier.

I can see the code is running in extensions_override because I changed the
httptimeout to 5 seconds (which I can see reflected in the log). Still openCnam
is queried though.

- Executing [[email protected]:20] Gosub("PJSIP/Main-00001802", "cidlookup,cidlookup_1,1()") in new stack
    -- Executing [[email protected]:1] Set("PJSIP/Main-00001802", "CURLOPT(httptimeout)=5") in new stack
    -- Executing [[email protected]:2] Set("PJSIP/Main-00001802", "CALLERID(name)=ERIC") in new stack
    -- Executing [[email protected]:3] Set("PJSIP/Main-00001802", "DB(cidname/1845yyyyyyy)=ERIC") in new stack
    -- Executing [[email protected]:4] Return("PJSIP/Main-00001802", "") in new stack
    -- Executing [[email protected]:21] NoOp("PJSIP/Main-00001802", "CallerID Entry Point") in new stack

Then I tried commenting out openCnam in extensions_override and I get no cid info.

-- Executing [[email protected]:20] Gosub("PJSIP/Main-00001808", "cidlookup,cidlookup_1,1()") in new stack
-- Executing [[email protected]:1] Set("PJSIP/Main-00001808", "CURLOPT(httptimeout)=5") in new stack
-- Executing [[email protected]:2] Set("PJSIP/Main-00001808", "DB(cidname/1845yyyyyyy)=1845yyyyyyy") in new stack
-- Executing [[email protected]:3] Return("PJSIP/MainAnveo-00001808", "") in new stack
-- Executing [[email protected]:21] NoOp("PJSIP/MainAnveo-00001808", "CallerID Entry Point") in new stack

Stewart1 · August 23, 2020, 5:02am

Sorry, I missed an error in the original attempt:

[cidlookup]
include => cidlookup-custom
exten => cidlookup_1,n(continue),GotoIf($[${DB_EXISTS(cidname/${CALLERID(num)})} = 1]?cidlookup,cidlookup_return,1)
exten => cidlookup_1,1,Set(CURLOPT(httptimeout)=7)
exten => cidlookup_1,n,Set(CALLERID(name)=${CURL(https://username:[email protected]/v2/phone/${CALLERID(num)}?format=pbx&ref=freepbx)})
exten => cidlookup_1,n,Set(DB(cidname/${CALLERID(num)})=${CALLERID(name)})
exten => cidlookup_1,n,Return()

exten => cidlookup_return,1,ExecIf($["${DB(cidname/${CALLERID(num)})}" != ""]?Set(CALLERID(name)=${DB(cidname/${CALLERID(num)})}))
exten => cidlookup_return,n,Return()

;--== end of [cidlookup] ==--;

Should be

[cidlookup]
exten => cidlookup_1,1,GotoIf($[${DB_EXISTS(cidname/${CALLERID(num)})} = 1]?cidlookup,cidlookup_return,1)
exten => cidlookup_1,n,Set(CURLOPT(httptimeout)=7)
exten => cidlookup_1,n,Set(CALLERID(name)=${CURL(https://username:[email protected]/v2/phone/${CALLERID(num)}?format=pbx&ref=freepbx)})
exten => cidlookup_1,n,Set(DB(cidname/${CALLERID(num)})=${CALLERID(name)})
exten => cidlookup_1,n,Return()

exten => cidlookup_return,1,ExecIf($["${DB(cidname/${CALLERID(num)})}" != ""]?Set(CALLERID(name)=${DB(cidname/${CALLERID(num)})}))
exten => cidlookup_return,n,Return()

;--== end of [cidlookup] ==--;

If this doesn’t help, post a new log and state whether the DB entry was actually present, before and after.

volkswagner · August 23, 2020, 1:33pm

We are getting closer

Here is partial log after making your edits.

-- Executing [[email protected]:20] Gosub("PJSIP/Main-0000180e", "cidlookup,cidlookup_1,1()") in new stack
-- Executing [[email protected]:1] GotoIf("PJSIP/Main-0000180e", "1?cidlookup,cidlookup_return,1") in new stack
-- Goto (cidlookup,cidlookup_return,1)
-- Executing [[email protected]:1] ExecIf("PJSIP/Main-0000180e", "1?Set(CALLERID(name)=1845yyyyyyy)") in new stack
-- Executing [[email protected]:2] Return("PJSIP/Main-0000180e", "") in new stack
-- Executing [[email protected]:21] NoOp("PJSIP/Main-0000180e", "CallerID Entry Point") in new stack

It appears to recognize the number is in the Asterisk database because it doesn’t query OpenCnam.
The callerID name is not pulled from the DB though.

Here is my new extensions_override.conf

[cidlookup]
exten => cidlookup_1,1,GotoIf($[${DB_EXISTS(cidname/${CALLERID(num)})} = 1]?cidlookup,cidlookup_return,1)
exten => cidlookup_1,n,Set(CURLOPT(httptimeout)=5)
exten => cidlookup_1,n,Set(CALLERID(name)=${CURL(https://username:[email protected]/v2/phone/${CALLERID(num)}?format=pbx&ref=freepbx)})
exten => cidlookup_1,n,Set(DB(cidname/${CALLERID(num)})=${CALLERID(name)})
exten => cidlookup_1,n,Return()

exten => cidlookup_return,1,ExecIf($["${DB(cidname/${CALLERID(num)})}" != ""]?Set(CALLERID(name)=${DB(cidname/${CALLERID(num)})}))
exten => cidlookup_return,n,Return()

;--== end of [cidlookup] ==--;

Actually, after more research, it seems the extensions_override.conf changed the DB entry.
It replaced the callerID name with the phone number. I can see this now in the phonebook.
My caller ID name and number are the same, where it used to show my full name in the name
column.

Stewart1 · August 23, 2020, 2:59pm

Possibly it was stored incorrectly by a previous iteration.

Manually delete your phonebook entry. Call in twice and check the logs. The first time should do the lookup and both return and store the name. Check the name in phonebook. The second time should return the name from the phonebook but not alter it. If trouble, post both logs.

volkswagner · August 23, 2020, 4:07pm

I think you are correct about previous itterations causing the bad entry in phonebook.

With my current extensions_override.conf:

[cidlookup]
exten => cidlookup_1,1,GotoIf($[${DB_EXISTS(cidname/${CALLERID(num)})} = 1]?cidlookup,cidlookup_return,1)
exten => cidlookup_1,n,Set(CURLOPT(httptimeout)=5)
exten => cidlookup_1,n,Set(CALLERID(name)=${CURL(https://username:[email protected]/v2/phone/${CALLERID(num)}?format=pbx&ref=freepbx)})
exten => cidlookup_1,n,Set(DB(cidname/${CALLERID(num)})=${CALLERID(name)})
exten => cidlookup_1,n,Return()

exten => cidlookup_return,1,ExecIf($["${DB(cidname/${CALLERID(num)})}" != ""]?Set(CALLERID(name)=${DB(cidname/${CALLERID(num)})}))
exten => cidlookup_return,n,Return()

;--== end of [cidlookup] ==--;

The phonebook isn’t updated at all.

I deleted the phonebook entry, called and had an OpenCnam lookup, but the phonebook
was not updated. I manually added the entry and the next call found the entry in phonebook
and used that rather than api call to openCnam.

Call-1

Executing [[email protected]:20] Gosub("PJSIP/MainAnveo-0000181e", "cidlookup,cidlookup_1,1()") in new stack
      -- Executing [[email protected]:1] GotoIf("PJSIP/Main-0000181e", "0?cidlookup,cidlookup_return,1") in new stack
        -- Executing [[email protected]:2] Set("PJSIP/Main-0000181e", "CURLOPT(httptimeout)=5") in new stack
        -- Executing [[email protected]:3] Set("PJSIP/Main-0000181e", "CALLERID(name)=ERIC") in new stack
        -- Executing [[email protected]:4] Set("PJSIP/Main-0000181e", "DB(cidname/1845yyyyyyy)=ERIC") in new stack
        -- Executing [[email protected]:5] Return("PJSIP/Main-0000181e", "") in new stack

Call-2

-- Executing [[email protected]:20] Gosub("PJSIP/Main-00001821", "cidlookup,cidlookup_1,1()") in new stack
-- Executing [[email protected]:1] GotoIf("PJSIP/Main-00001821", "1?cidlookup,cidlookup_return,1") in new stack
-- Goto (cidlookup,cidlookup_return,1)
-- Executing [[email protected]:1] ExecIf("PJSIP/Main-00001821", "1?Set(CALLERID(name)=Eric)") in new stack
-- Executing [[email protected]:2] Return("PJSIP/Main-00001821", "") in new stack
-- Executing [[email protected]:21] NoOp("PJSIP/Main-00001821", "CallerID Entry Point") in new stack

lgaetz · August 23, 2020, 4:08pm

It’s one thing to hack dialplan for knowledge and fun, but I will point out again that the cache feature you’re looking for is native to Superfecta. None of this is necessary.

volkswagner · August 23, 2020, 4:24pm

Thank you @lgaetz

I was looking into CID Superfecta, but the documentation is sparse.

I don’t know where Superfecta stores cache.
It seems CID Superfecta can use the Asterisk Phonebook as a source, but
it’s not where it stores its cache.

I also couldn’t find if I’m supposed to use CID Superfecta exclusively. Through testing
it does seem I need NOT use CID sources in the inbound route when using
CID Superfecta (on that same inbound route).

I do like all of the options in CID Superfecta, but I wish there were more docs to understand how I’m supposed to use it and how it works. For example, I’m not sure if I use GoogleContacts, will Superfecta cache this result as well, so it won’t need to hit Google next time the same number is calling in (within the cache time period)?

I tested CID Superfecta and successfully pulled data from the Asterisk Phonebook.
I guess it’s okay if Superfecta stores it’s own cache and can also lookup existing entries in
the asterisk phonebook. It would be nice to know where it stores the cache though.

It also appears like CID Superfecta would be great to help eliminate spam.

EDIT:
I guess my Google Contacts question is mute since this won’t work until the module gets
past Google’s new security requirements. See report here.