[Solved] Fritzbox TR064 binding; sometimes not processing caller ID

Add-ons Bindings
1
  • Platform information:
    • Hardware: Raspberry Pi 3 Model B Rev 1.2_
    • System: Host: rpi3ohv2 Kernel: 5.4.51-v7+ armv7l bits: 32 Console: tty 2
    • Distro: Raspbian GNU/Linux 10 (buster)
    • OpenJDK Runtime Environment (Zulu 8.31.1.122-linux_aarch32hf) (build 1.8.0_181-b122)
  • Version: 2.5.10 (Build) (apt-get), text-based config
    • binding = astro,exec,logreader,network,ntp,systeminfo,fritzboxtr0641,expire1,mqtt1,weather1
    • ui = paper,basic,classic,restdocs
    • persistence = rrd4j,mapdb
    • action = mail,mqtt
    • transformation = map,javascript,xslt,scale,jsonpath

openhab-binding-fritzboxtr0641 │ 1.14.0 │ x │ Started │ openhab-addons-2.5.10 │ Fritzbox TR064 Binding

I have observed that the binding does not pick up a caller ID, while the DECT phone does. I can’t tell, whether this is a new thing, as I never paid much attention to it.

Do others experience the same issue?

I use that binding for many years, and recently reviewed, whether my rule and item syntax corresponds to the documentation… which it does.
The openhab.log will show an entry with the local and calling number pair, when a call comes in. But, as I observed, I have quite a few calls (maybe 40%) where the calling number is empty… while the landline phone (and even FritzPhone on the iPhone) show a caller ID.

Here some log files, also showing the discrepancy between event and openhab log files:

2020-11-25 12:52:44.723 [vent.ItemStateChangedEvent] - fbox_IncomingCallResolved changed from , to 0754246535,Joe Milao - Mays (Work)
2020-11-25 12:52:44.726 [vent.ItemStateChangedEvent] - fbox_IncomingCall changed from , to 0754246535,0733433044

2020-11-25 12:52:44.706 [INFO ] [.smarthome.model.script.Fritzbox.1.0] - Call coming in...
2020-11-25 12:52:44.717 [INFO ] [.smarthome.model.script.Fritzbox.1.1] - tmpIncomingCall...............: ,
2020-11-25 12:52:44.723 [INFO ] [.smarthome.model.script.Fritzbox.1.2] - tmpLastCallerNumber...........:
2020-11-25 12:52:44.730 [INFO ] [.smarthome.model.script.Fritzbox.1.x] - No caller ID provided means...: nothing to process; over and out.

Items and rules

Switch  fbox_Ringing					"Phone ringing in [%s]"								<phone>		(gFritzBox)	{ fritzboxtr064="callmonitor_ringing" }
Call    fbox_IncomingCall				"Call [%1$s to %2$s]"								<phone>		(gFritzBox)	{ fritzboxtr064="callmonitor_ringing" }
Call    fbox_IncomingCallResolved		"Call (resolved) [%1$s to %2$s]"					<phone>		(gFritzBox)	{ fritzboxtr064="callmonitor_ringing:resolveName" }
String  fBox_LastCallerNumber			"Last caller's number [%s]"							<phone>		(gFritzBox)
String  fBox_LastCallerName				"Last caller's name [%s]"							<phone>		(gFritzBox)

rule "Fritzbox: Incoming call, get number and resolve name from phonebook"
    when
        Item fbox_Ringing changed from OFF to ON
    then
        logInfo(logPrefix + "1.0", "Call coming in...")

        val tmpIncomingCall = fbox_IncomingCall.state as StringListType
        val String tmpLastCallerNumber = tmpIncomingCall.getValue(1)

        val String tmpLastCallerNumber0 = tmpIncomingCall.getValue(0)
        logInfo(logPrefix + "1.1", "tmpIncomingCall...............: {}", tmpIncomingCall)
        logInfo(logPrefix + "1.2", "tmpLastCallerNumber...........: {}", tmpLastCallerNumber)

        var tmpLastCallResolved = fbox_IncomingCallResolved.state as StringListType
        logInfo(logPrefix + "1.3", "tmpLastCallResolved...........: {}", tmpLastCallResolved)

        var tmpLastCallerName = tmpLastCallResolved.getValue(1)
        logInfo(logPrefix + "1.4", "tmpCallerName.................: {}", tmpLastCallerName)

        val stringCallerNumber = transform("JS", "fb_phoneNumber.js", tmpLastCallerNumber)
        logInfo(logPrefix + "1.5", "stringCallerNumber............: {}", stringCallerNumber)

        // remove the called (own) number from caller string
        tmpLastCallerName = tmpLastCallerName.removeStart("0754246535##")

        if (tmpLastCallerName.startsWith("Name not found for"))
        {
            tmpLastCallerName = "Unknown"
        }

        logInfo(logPrefix + "1.6", "stringCallerNumber............: {}", stringCallerNumber)
        logInfo(logPrefix + "1.7", "tmpName.......................: {}", tmpLastCallerName)
end
2

Your Openhab is executing the rule to fast :slight_smile:

Time of Events
First, the Switch fbox_Ringing recieves the command “ON”. (Miliisecond 706 or before, should be in the event log a line above)
Rule gets started (Milliseconds 706)
Rule reads the item fbox_IncomingCall (Millisecond 717)
Item fbox_IncomingCall recieves the number (Millisecond 726)

An easy, but bad solution would be delay the rule a bit by Thread.sleep.

But the best solution might to change the condition to the item you are actualy going to use - fbox_IncomingCall

3

What should I do with it?
What do you suggest I change?

My items/rules are per binding documentation… I noticed the mangled time stamps, but can’t tell why that is. I’d expect that the events come before the rules.

[update] I think get it now… after sorting these lines… I added a 100 ms delay which should fix this problem.

4

Well, “bad” or not… 100ms does work… Thanks.

2020-11-28 14:47:57.992 [vent.ItemStateChangedEvent] - fbox_IncomingCallResolved changed from , to 0754246535,Name not found for 0290991633
2020-11-28 14:47:57.996 [vent.ItemStateChangedEvent] - fbox_IncomingCall changed from , to 0754246535,0290991633
2020-11-28 14:47:59.517 [INFO ] [.smarthome.model.script.Fritzbox.1.0] - Call coming in...
2020-11-28 14:47:59.629 [INFO ] [.smarthome.model.script.Fritzbox.1.1] - tmpIncomingCall...............: 0754246535,0290991633
2020-11-28 14:47:59.645 [INFO ] [.smarthome.model.script.Fritzbox.1.2] - tmpLastCallerNumber...........: 0290991633
2020-11-28 14:47:59.652 [INFO ] [.smarthome.model.script.Fritzbox.1.3] - tmpLastCallResolved...........: 0754246535,Name not found for 0290991633
2020-11-28 14:47:59.656 [INFO ] [.smarthome.model.script.Fritzbox.1.4] - tmpCallerName.................: Name not found for 0290991633
2020-11-28 14:47:59.737 [INFO ] [.smarthome.model.script.Fritzbox.1.5] - stringCallerNumber............: 02 9099 1633
2020-11-28 14:47:59.747 [INFO ] [.smarthome.model.script.Fritzbox.1.6] - tmpName.......................: Unknown

Problem solved… :slight_smile: