OH3 Rule for tr064 binding does not work

Hello,

the following rule “Ausgehender Anruf” is intended to cause, among other things, that the name of the called party is stored permanently via the dummy “Flag_LetzteAusgendeNr.postUpdate(calledNumber)” until the next call.
Unfortunately, this only works for a short time, after which UNDEV is displayed again.
While the alternative rule “Eingehender Anruf” works very well, I can’t find anything wrong with it.
Can someone tell me what needs to be changed?
Thanks in advance!

rule "Eingehender Anruf"
when
    Item fritzCallRinging changed to RINGING 
then
    // zerlege die rufnummern mit avmfritz bindung

    val incCall = fritzIncomingCall.state as StringListType

    val ourNumber = incCall.getValue(0)
    val callerNumber = incCall.getValue(1)

    val tr064Actions = getActions("tr064","tr064:fritzbox:1")
    val callerName = tr064Actions.phonebookLookup(callerNumber)

    var String msg = "Der Anruf von" + " '" + fritzIncomingCallCaller.state +"' " + " Telefon-Nr. " + callerNumber + " erfolgte an die eigene Nr. " + ourNumber
    logInfo("FRITZ!Box", msg)
    Flag_LetzterEingehenderRuf.postUpdate(callerName)
    Flag_LetzteEingehendeNr.postUpdate(callerNumber)
    Flag_LetzteELeitung.postUpdate(ourNumber)
    logInfo("RuleLastCall", "Der Anruf an" + " '" + fritzIncomingCallCaller.state +"' " + calledNumber + " wurde als letztes Gespräch gespeichert.")
	   //actions.sendMessage(msg, "openHAB")
end

rule "Ausgehender Anruf"
when
    Item fritzCallRinging changed to DIALING 
then
    // zerlege die rufnummern mit avmfritz bindung

    val outCall = fritzOutgoingCall.state as StringListType
 
    var String calledNumber = outCall.getValue(0)
    var String ourNumber = outCall.getValue(1)

    val tr064Actions = getActions("tr064","tr064:fritzbox:1")
    val calleeName = tr064Actions.phonebookLookup(calledNumber) 

    var String msg = "Der Anruf an" + " '" + calleeName +"' " + " Telefon-Nr. " + calledNumber + " erfolgte über die eigene Nr. " + ourNumber
    logInfo("FRITZ!Box", msg)
    Flag_LetzterAusgehenderRuf.postUpdate(calleeName)
    Flag_LetzteAusgendeNr.postUpdate(calledNumber)
    Flag_LetzteALeitung.postUpdate(ourNumber)
    logInfo("RuleLastCall", "Der Anruf an" + " '" + calleeName +"' " + calledNumber + " wurde als letztes Gespräch gespeichert.")
	   //actions.sendMessage(msg, "openHAB")
end

rule "Verbindung aufgebaut - ausgehend"
when
    Item fritzCallRinging changed from DIALING to ACTIVE
then
    logInfo("FRITZ!Box", "Ausgehender Anruf: Verbindung hergestellt")
end

rule "Verbindung hergestellt - eingehend"
when
    Item fritzCallRinging changed from RINGING to ACTIVE
then
    logInfo("FRITZ!Box", "Eingehender Anruf: Verbindung hergestellt")
end


rule "Verbindung unterbrochen"
when
    Item CallStatfritzCallRinging changed from ACTIVE to IDLE
then
    logInfo("FRITZ!Box", "Aktiver Anruf: Verbindung unterbrochen")
end

Something updates your Item. Is it linked to any binding channels? Have you set an “expire” function on it, in metadata? Is it mentioned in other rules?

I assume that you are looking at your logs to see the messages you helpfully placed, to show when rules run and with what values.

I don’t think so, this is the corresponding text-based item:

// Equipment representing thing:
// avmfritz:fritzbox:192_168_1_1
// (gCALLMONITOR)

Group avmfritz "avmfritz" ["Equipment"]

// Points:

Group gCALLMONITOR "Call Monitor" ["Equipment"]

Call fritzIncomingCall   "Incoming Call [from %2$s to %1$s]" (gCALLMONITOR) ["Status"] { channel="avmfritz:fritzbox:192_168_1_1:incoming_call" }

Call fritzActiveCall     "Active Call [from %1$s]"           (gCALLMONITOR) ["Status"] { channel="avmfritz:fritzbox:192_168_1_1:active_call" }

Call fritzOutgoingCall   "Outgoing Call [from %2$s to %1$s]" (gCALLMONITOR) ["Status"] { channel="avmfritz:fritzbox:192_168_1_1:outgoing_call" }

String fritzCallRinging  "Status [%s]"                       (gCALLMONITOR) ["Status"] { channel="avmfritz:fritzbox:192_168_1_1:call_state" }

String FritzTemplate     "Vorlage anwenden"                  (gCALLMONITOR) ["Status"] { channel="avmfritz:fritzbox:192_168_1_1:apply_template" }

// resolved numbers (only if TR-064 binding is installed)

String fritzIncomingCallCallee "Incoming Call - Callee [%s]" (gCALLMONITOR) ["Status"] { channel="tr064:fritzbox:1:incoming_call" [profile="transform:PHONEBOOK", phonebook="tr064_3Afritzbox_3A1"] }

String fritzIncomingCallCaller "Incoming Call - Caller [%s]" (gCALLMONITOR) ["Status"] { channel="tr064:fritzbox:1:incoming_call" [profile="transform:PHONEBOOK", phonebook="tr064_3Afritzbox_3A1", phoneNumberIndex=1, matchcount="8"] }

String fritzActiveCallCaller   "Active Call - Caller [%s]"   (gCALLMONITOR) ["Status"] { channel="tr064:fritzbox:1:active_call" [profile="transform:PHONEBOOK", phonebook="tr064_3Afritzbox_3A1"] }

String fritzOutgoingCallCallee "Outgoing Call - Callee [%s]" (gCALLMONITOR) ["Status"] { channel="tr064:fritzbox:1:outgoing_call" [profile="transform:PHONEBOOK", phonebook="tr064_3Afritzbox_3A1"] }

String fritzOutgoingCallCaller "Outgoing Call - Caller [%s]" (gCALLMONITOR) ["Status"] { channel="tr064:fritzbox:1:outgoing_call" [profile="transform:PHONEBOOK", phonebook="tr064_3Afritzbox_3A1", phoneNumberIndex=1, matchcount="8"] }

Call IncomingCallResolved "Caller name: [%s]"                (gCALLMONITOR) ["Status"] { channel="tr064:fritzbox:1:incoming_call" [profile="transform:PHONEBOOK", phonebook="tr064_3Afritzbox_3A1", phoneNumberIndex="1", matchCount="8"] }

String Flag_LetzterAusgehenderRuf "Name Angerufener"
String Flag_LetzteAusgendeNr      "angerufene Nummer"
Number Flag_LetzteALeitung        "über ausgehende Nummer"
String Flag_LetzterEingehenderRuf "Name Anrufer"
string Flag_LetzteEingehendeNr    "anrufende Nummer"
Number Flag_LetzteELeitung        "über eingende Nummer"

By the way, the line:

var String msg = "Der Anruf an" + " '" + calleeName +"' " + " Telefon-Nr. " + calledNumber + " erfolgte über die eigene Nr. " + ourNumber

is also displayed correctly in the log file.

Okay, so what is in your log file around the time of the mystery change to UNDEV (which looks like a corrupted UNDEF)

Alright, that’s a string type Item.

Is calledNumber a string? I don’t know, it was derived from a list object. I think I’d make sure -
Flag_LetzteAusgendeNr.postUpdate(calledNumber.toString)

Edit - is there some confusion with Item Flag_LetzteEingehendeNr ?
That one is defined with invalid syntax

string / String

Further Edit -
I’d be pretty sure that your rule is running perhaps when you don’t expect it. And then you may run into issues examined here -

where you might very well get UNDEF for caller number when there is no active call etc.
That’s assuming the state really is UNDEF. Your logging should reveal this.

Hi,
in general, if you are interested in incoming / outgoing number, why do you listen to “call_state” channel instead of “incoming_call” and “outgoing_call”? Maybe call_state item is already updated but outgoing_call item not yet?
rfu

@rossko57
You showed me a lot of ways to look for a source of error. I did that too, but without success. I’ve invested a lot of time and I’m pretty frustrated by now.
What is strange is that the dummy item correctly displays the phone number for about 5 seconds and then updates to “UNDEV”.

@rfuh
I’m sorry, but I don’t really understand your comment.

@all
Do you know any other solutions to get the desired values?

Many Thanks

No, something updates it. It is not easy to identify what, so we must use logic & elimination.
Accuracy is important - really UNDEV? That would eliminate a few possibilities.

Can we see your logs? You’ve gone to the trouble of putting logging in your rules, but not shared the results.

sorry if I was confusing you…

I have an Item “Anruf” which is mapped to avmfritz binding channel incoming_call. Then I have a rule to react on this:

rule "Anruf"
when
    Item Anruf changed
then
...

This rule gets triggered when the incoming call item has a value, and the value is the numbers involved. No need to check or map the call_state channel at all…

I don’t map outgoing calls, but the procedure would be the same with outgoing_call channel.

As OH is event based, in principle it might be that

  1. call_state item is updated
  2. your rule runs
  3. incoming_call item is updated

in this case, your rule would still see UNDEF as value for the incoming_call.

But, as you say it updates for few seconds and then goes to UNDEF, I agree that it is most likely not the cause of your issue, it wouldn’t update to the right value at all if this would happen.

rfu

@rossko57

Sorry, “UNDEF” is displayed at the moment when the first ring is heard. Before that, as already written, the item shows the selected number.

Here is the requested excerpt from the log file:

2022-09-26 19:13:26.493 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'fritzOutgoingCall' changed from UNDEF to 08001234567,654321
2022-09-26 19:13:26.493 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'fritzCallRinging' changed from IDLE to DIALING
2022-09-26 19:13:26.658 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'Flag_LetzterAusgehenderRuf' changed from aaaa to bbbb
2022-09-26 19:13:26.659 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'Flag_LetzteAusgendeNr' changed from UNDEF to 08001234567
.....
2022-09-26 19:13:32.495 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'fritzActiveCall' changed from UNDEF to 08001234567,
2022-09-26 19:13:32.495 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'fritzOutgoingCall' changed from 08001234567,654321 to UNDEF
2022-09-26 19:13:32.495 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'Flag_LetzteAusgendeNr' changed from 08001234567 to UNDEF
2022-09-26 19:13:32.496 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'fritzCallRinging' changed from DIALING to ACTIVE
.....
2022-09-26 19:13:36.496 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'fritzActiveCall' changed from 08001234567, to UNDEF
2022-09-26 19:13:36.496 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'fritzCallRinging' changed from ACTIVE to IDLE

@rfuh

I assume you have a similar rule running successfully. May I ask if you would like to share these and the items here?

Can we see your openhab.log as well (including the rule logging) for the same time frame, to understand the sequence?

The openhab.log at this point (nothing more is saved):

2022-09-26 19:13:26.654 [INFO ] [.openhab.core.model.script.FRITZ!Box] - Der Anruf an 'bbbb'  Telefon-Nr. 08001234567 erfolgte über die eigene Nr. 123456
2022-09-26 19:13:26.658 [INFO ] [enhab.core.model.script.RuleLastCall] - Der Anruf an 'bbbb' 08001234567 wurde als letztes Gespräch gespeichert.
2022-09-26 19:13:32.500 [INFO ] [.openhab.core.model.script.FRITZ!Box] - Ausgehender Anruf: Verbindung hergestellt

Pretty sure you have another rule somewhere, triggered by one of the fritzXXX Items, that is also updating Flag_LetzteAusgendeNr
Consider other xxx.rules files, and also if you have experimented with GUI rules or Node Red or suchlike.

Prove the theory by changing the name of your Item, and changing the one place that you know it should get updated by rule.
This would also eliminate out any weird feedback from a GUI widget, though I don’t suspect that at all as no commands are involved.

The problem is solved thanks to @rossko57’s kind help! It was very simple: the dummy item “Flag_LetzteAusgendeNr” was removed and then a new item with a different name was created. That’s it.

I have one more question, maybe I can ask it here:
The AVM FRITZ!BOX binding provides an “apply_template” channel. I would like to document all incoming and outgoing calls about it, but I can’t find any instructions on how to do this. Are you familiar with this or should I better create a new topic?