tr-064 v3.1.x (Latest Repo) Diskussion

[apollon77]

@crunchip Wenns danach tat keine Ahnung warum das kam. Kam es als DU von info auf Debug umgestellt hast?

[crunchip]

@apollon77 kann sein, das es durch umstellen/neustarten war

durchs (auf debug) stellen, wurden nun auch die DP wieder aktualisiert

hier das log
ausgehender Anruf und Gespräch angenommen

tr-064.0	2020-02-18 23:35:50.179	debug	(16737) in updateAll
tr-064.0	2020-02-18 23:35:48.796	debug	(16737) system.adapter.admin.0: logging false
tr-064.0	2020-02-18 23:35:41.757	debug	(16737) Processing call ID5631 (call.type = 3)
tr-064.0	2020-02-18 23:35:41.757	debug	(16737) Result Callist JSON: {"root":{"timestamp":"1463936401","call":{"id":"5631","type":"3","called":"xxxxxxxx","caller":"SIP: xxxxx","callernumber":"xxxxx","name":"xxxxxxx ","numbertype"
tr-064.0	2020-02-18 23:35:41.581	debug	(16737) State changed: tr-064.0.calllists.outbound.html = {"val":"<div>The last call was from at from </div><div>outbound: 216<table><tr><td>10.02.20 08:41</td><td>Isolde Unzeitig</td><td>SIP: xxxx
tr-064.0	2020-02-18 23:35:41.580	debug	(16737) State changed: tr-064.0.calllists.outbound.count = {"val":216,"ack":true,"ts":1582065341554,"q":0,"from":"system.adapter.tr-064.0","user":"system.user.admin","lc":1582065341554}
tr-064.0	2020-02-18 23:35:41.575	debug	(16737) State changed: tr-064.0.calllists.outbound.json = {"val":"[{\"id\":5631,\"type\":\"3\",\"called\":\"xxxxxxx\",\"caller\":\"SIP: xxxxx\",\"callernumber\":\"xxxxx\",\"name\":\"xxxxxx
tr-064.0	2020-02-18 23:35:41.568	debug	(16737) State changed: tr-064.0.calllists.all.html = {"val":"<div>The last call was from at from </div><div>all: 455<table><tr><td>17.02.20 13:45</td><td>xxxxxx</td><td>SIP: xxxxx</td></tr><
tr-064.0	2020-02-18 23:35:41.566	debug	(16737) State changed: tr-064.0.calllists.all.count = {"val":455,"ack":true,"ts":1582065341553,"q":0,"from":"system.adapter.tr-064.0","user":"system.user.admin","lc":1582065341553}
tr-064.0	2020-02-18 23:35:41.561	debug	(16737) State changed: tr-064.0.calllists.all.json = {"val":"[{\"id\":5631,\"type\":\"3\",\"called\":\"xxxxxxxxxxx\",\"caller\":\"SIP: xxxxx\",\"callernumber\":\"xxxxx\",\"name\":\"xxxxxxx \",
tr-064.0	2020-02-18 23:35:41.544	debug	(16737) Processing call ID5631 (call.type = 3)
tr-064.0	2020-02-18 23:35:41.543	debug	(16737) Result Callist JSON: {"root":{"timestamp":"1463936401","call":{"id":"5631","type":"3","called":"xxxxxxxxxx","caller":"SIP: xxxx","callernumber":"xxxxx","name":"xxxx ","numbertype"
tr-064.0	2020-02-18 23:35:41.238	debug	(16737) State changed: tr-064.0.callmonitor.toPauseState-0 = {"val":"end","ack":true,"ts":1582065341189,"q":0,"from":"system.adapter.tr-064.0","user":"system.user.admin","lc":1582065341189}
tr-064.0	2020-02-18 23:35:41.234	debug	(16737) State changed: tr-064.0.callmonitor.toPauseState = {"val":"end","ack":true,"ts":1582065341189,"q":0,"from":"system.adapter.tr-064.0","user":"system.user.admin","lc":1582065341189}
tr-064.0	2020-02-18 23:35:41.229	debug	(16737) State changed: tr-064.0.callmonitor.lastCall.json = {"val":"{\"caller\":\"xxxxxxxx\",\"callee\":\"xxxxxxx\",\"extension\":\"0\",\"timestamp\":\"18.02.20 23:35:07\",\"id\":\"0\",\"_type\":\"
tr-064.0	2020-02-18 23:35:41.218	debug	(16737) State changed: tr-064.0.callmonitor.lastCall.timestamp = {"val":"18.02.20 23:35:41","ack":true,"ts":1582065341188,"q":0,"from":"system.adapter.tr-064.0","user":"system.user.admin","lc":158206
tr-064.0	2020-02-18 23:35:41.217	debug	(16737) State changed: tr-064.0.callmonitor.lastCall.duration = {"val":5,"ack":true,"ts":1582065341188,"q":0,"from":"system.adapter.tr-064.0","user":"system.user.admin","lc":1582065341188}
tr-064.0	2020-02-18 23:35:41.214	debug	(16737) State changed: tr-064.0.callmonitor.lastCall.calleeName = {"val":"xxxxxx ","ack":true,"ts":1582065341188,"q":0,"from":"system.adapter.tr-064.0","user":"system.user.admin","lc":158206534
tr-064.0	2020-02-18 23:35:41.207	debug	(16737) State changed: tr-064.0.callmonitor.lastCall.callerName = {"val":"","ack":true,"ts":1582065341188,"q":0,"from":"system.adapter.tr-064.0","user":"system.user.admin","lc":1582065341188}
tr-064.0	2020-02-18 23:35:41.206	debug	(16737) State changed: tr-064.0.callmonitor.lastCall.timestamp = {"val":"18.02.20 23:35:07","ack":true,"ts":1582065341187,"q":0,"from":"system.adapter.tr-064.0","user":"system.user.admin","lc":158206
tr-064.0	2020-02-18 23:35:41.200	debug	(16737) State changed: tr-064.0.callmonitor.lastCall.callee = {"val":"xxxxxxx","ack":true,"ts":1582065341187,"q":0,"from":"system.adapter.tr-064.0","user":"system.user.admin","lc":1582065341187}
tr-064.0	2020-02-18 23:35:41.197	debug	(16737) State changed: tr-064.0.callmonitor.lastCall.caller = {"val":"xxxxxxxxx","ack":true,"ts":1582065341186,"q":0,"from":"system.adapter.tr-064.0","user":"system.user.admin","lc":1582065341186}
tr-064.0	2020-02-18 23:35:41.183	debug	(16737) callMonitor.set: type=lastCall caller=xxxx callee=xxxxx calleeName=xxxxx
tr-064.0	2020-02-18 23:35:41.182	debug	(16737) Search number 0049xxxxxxxx in phonebook: undefined
tr-064.0	2020-02-18 23:35:41.179	debug	(16737) New Call data lastCall: {"caller":"xxx","callee":"xxxxxxxxx","extension":"0","timestamp":"18.02.20 23:35:07","id":"0","_type":"connect","callerName":"","calleeName":"xxxxxxxx ","type
tr-064.0	2020-02-18 23:35:41.179	debug	(16737) Callmonitor Raw: 18.02.20 23:35:41;DISCONNECT;0;5;
tr-064.0	2020-02-18 23:35:39.554	debug	(16737) in updateAll
tr-064.0	2020-02-18 23:35:28.889	debug	(16737) in updateAll
tr-064.0	2020-02-18 23:35:28.452	debug	(16737) State changed: tr-064.0.callmonitor.toPauseState-0 = {"val":"connect","ack":true,"ts":1582065328404,"q":0,"from":"system.adapter.tr-064.0","user":"system.user.admin","lc":1582065328404}
tr-064.0	2020-02-18 23:35:28.450	debug	(16737) State changed: tr-064.0.callmonitor.toPauseState = {"val":"connect","ack":true,"ts":1582065328403,"q":0,"from":"system.adapter.tr-064.0","user":"system.user.admin","lc":1582065328403}
tr-064.0	2020-02-18 23:35:28.446	debug	(16737) State changed: tr-064.0.callmonitor.connect.json = {"val":"{\"caller\":\"981400\",\"callee\":\"xxxxxxx\",\"extension\":\"0\",\"timestamp\":\"18.02.20 23:35:07\",\"id\":\"0\",\"_type\":\"c
tr-064.0	2020-02-18 23:35:28.445	debug	(16737) State changed: tr-064.0.callmonitor.connect.timestamp = {"val":"18.02.20 23:35:28","ack":true,"ts":1582065328398,"q":0,"from":"system.adapter.tr-064.0","user":"system.user.admin","lc":1582065
tr-064.0	2020-02-18 23:35:28.445	debug	(16737) State changed: tr-064.0.callmonitor.connect.calleeName = {"val":"xxxxxxx ","ack":true,"ts":1582065328398,"q":0,"from":"system.adapter.tr-064.0","user":"system.user.admin","lc":1582065328
tr-064.0	2020-02-18 23:35:28.444	debug	(16737) State changed: tr-064.0.callmonitor.connect.callerName = {"val":"","ack":true,"ts":1582065328398,"q":0,"from":"system.adapter.tr-064.0","user":"system.user.admin","lc":1582065328398}
tr-064.0	2020-02-18 23:35:28.436	debug	(16737) State changed: tr-064.0.callmonitor.connect.timestamp = {"val":"18.02.20 23:35:07","ack":true,"ts":1582065328397,"q":0,"from":"system.adapter.tr-064.0","user":"system.user.admin","lc":1582065
tr-064.0	2020-02-18 23:35:28.429	debug	(16737) State changed: tr-064.0.callmonitor.connect.callee = {"val":"xxxxxxxx","ack":true,"ts":1582065328396,"q":0,"from":"system.adapter.tr-064.0","user":"system.user.admin","lc":1582065328396}
tr-064.0	2020-02-18 23:35:28.428	debug	(16737) State changed: tr-064.0.callmonitor.connect.caller = {"val":"xxxxxxx","ack":true,"ts":1582065328396,"q":0,"from":"system.adapter.tr-064.0","user":"system.user.admin","lc":1582065328396}
tr-064.0	2020-02-18 23:35:28.388	debug	(16737) callMonitor.set: type=connect caller=xxxxxxx callee=xxxxxxxxx calleeName=xxxxxxxxx
tr-064.0	2020-02-18 23:35:28.386	debug	(16737) Search number 0049xxxxxxx in phonebook: undefined
tr-064.0	2020-02-18 23:35:28.383	debug	(16737) New Call data connect: {"caller":"xxxxxx","callee":"xxxxxxxxxxxxx","extension":"0","timestamp":"18.02.20 23:35:07","id":"0","_type":"outbound","callerName":"","calleeName":"xxxxxxxxxxxxx "}
tr-064.0	2020-02-18 23:35:28.381	debug	(16737) Callmonitor Raw: 18.02.20 23:35:28;CONNECT;0;0;xxxxxxxxx;
tr-064.0	2020-02-18 23:35:18.223	debug	(16737) in updateAll
tr-064.0	2020-02-18 23:35:13.153	debug	(16737) system.adapter.admin.0: logging true
tr-064.0	2020-02-18 23:35:07.589	debug	(16737) in updateAll
tr-064.0	2020-02-18 23:35:07.047	debug	(16737) State changed: tr-064.0.callmonitor.outbound.json = {"val":"{\"caller\":\"xxxxx\",\"callee\":\"xxxxxxxxxx\",\"extension\":\"0\",\"timestamp\":\"18.02.20 23:35:07\",\"id\":\"0\",\"_type\":\"
tr-064.0	2020-02-18 23:35:07.042	debug	(16737) State changed: tr-064.0.callmonitor.outbound.calleeName = {"val":"xxxxxx ","ack":true,"ts":1582065307024,"q":0,"from":"system.adapter.tr-064.0","user":"system.user.admin","lc":158206530
tr-064.0	2020-02-18 23:35:07.041	debug	(16737) State changed: tr-064.0.callmonitor.outbound.id = {"val":"0","ack":true,"ts":1582065307024,"q":0,"from":"system.adapter.tr-064.0","user":"system.user.admin","lc":1582065307024}
tr-064.0	2020-02-18 23:35:07.039	debug	(16737) State changed: tr-064.0.callmonitor.outbound.timestamp = {"val":"18.02.20 23:35:07","ack":true,"ts":1582065307023,"q":0,"from":"system.adapter.tr-064.0","user":"system.user.admin","lc":158206
tr-064.0	2020-02-18 23:35:07.036	debug	(16737) State changed: tr-064.0.callmonitor.outbound.extension = {"val":"0","ack":true,"ts":1582065307023,"q":0,"from":"system.adapter.tr-064.0","user":"system.user.admin","lc":1582065307023}
tr-064.0	2020-02-18 23:35:07.033	debug	(16737) State changed: tr-064.0.callmonitor.outbound.callee = {"val":"xxxxxxxxx","ack":true,"ts":1582065307022,"q":0,"from":"system.adapter.tr-064.0","user":"system.user.admin","lc":1582065307022}
tr-064.0	2020-02-18 23:35:07.019	debug	(16737) callMonitor.set: type=outbound caller=xxxxxxxx callee=xxxxxxx calleeName=xxxxxxxxxx
tr-064.0	2020-02-18 23:35:07.018	debug	(16737) Search number 0049xxxxxxx in phonebook: {"name":"xxxxxxxxxx ","normalizedName":"xxxxxxxxx","number":"0049xxxxxxx","id":"40","phonebookId":"0"}
tr-064.0	2020-02-18 23:35:07.018	debug	(16737) Search number 0049xxxxxxxxxx in phonebook: undefined
tr-064.0	2020-02-18 23:35:07.014	debug	(16737) New Call data outbound: {"caller":"xxxx","callee":"xxxxxxxxx","extension":"0","timestamp":"18.02.20 23:35:07","id":"0"}
tr-064.0	2020-02-18 23:35:07.013	debug	(16737) Callmonitor Raw: 18.02.20 23:35:07;CALL;0;0;xxxxx;xxxxxxxxxx;SIP0;
tr-064.0	2020-02-18 23:34:57.008	debug	(16737) in updateAll
tr-064.0	2020-02-18 23:34:55.054	debug	(16737) callmonitor connected
tr-064.0	2020-02-18 23:34:55.007	debug	(16737) starting callmonitor

tr-064.0	2020-02-18 23:34:54.370	debug	(16737) getVoIPCommonAreaCode: xxxxx
tr-064.0	2020-02-18 23:34:54.307	debug	(16737) getVoIPCommonCountryCode: 0049
tr-064.0	2020-02-18 23:34:54.255	debug	(16737) forEachConfiguredDevice
tr-064.0	2020-02-18 23:34:54.254	debug	(16737) createConfiguredDevices

[apollon77]

@crunchip Hm ... verstehen muss ich das nicht das es mit Debug tut und sonst nicht ?! WTF

[crunchip]

@apollon77 frag mich mal, ich versteh gar nix mehr
mal gehts, mal nicht, fällt halt immer auf, wenn keine Ansage kommt, da der trigger im script ja DP ringing ist

warum diese Meldung?, diese ist ja eigentlich meine Tel-nr. die ich angerufen habe und ist auch im Telefonbuch eingetragen.

Search number 0049xxxxxxxx in phonebook: undefined

[apollon77]

@crunchip kannst du mal auch andere States wenigstens loggen als trigger und nicht nur Ringring? Nicht das es nur an dem state liegt.

[crunchip]

@apollon77 könnte ich theoretisch, wenn ich nen passenden DP finde zum triggern, der sich auch bei eingehendem Anruf aktualisiert. so wie es jedoch momentan überblicke, aktualisiert keiner der DP´s die in Frage kommen könnten zum triggern.
Unabhängig davon, bleibt ja dennoch das Problem...das weder ein noch ausgehende Anrufe aktualisiert werden.
Die tr-064.0.calllists.xyz.json nur aktualisieren nach einem neustart.
ich sehe es ja an den Zeitstempeln ob eine Aktualisierung stattfand, aber ich beobachte das nochmal die Tage in Ruhe

[apollon77]

@crunchip genau den json hätte ich hetzt genommen weil der an sich immer aktualisiert wird.

[Latzi]

@apollon77 ich bekomme bei meinem iPhone gelegentlich die Meldung:

2020-02-19 07:12:33.622  - warn: tr-064.0 (755) forEachConfiguredDevice: in GetSpecificHostEntry 0(Latzi-iPhone/50:A6:7F:7D:FF:E2):Error: sendSOAPActionRequest Error action=GetSpecificHostEntry serviceType=urn:dslforum-org:service:Hosts:1: 500 - {"code":500}

und dabei verschwindet kurzzeitig die Anwesenheit (im Zehntelskeunden-Bereich). Ist das bekannt und kann ich dagegen etwas tun? Die Android zeigen dieses Verhalten nicht.

[apollon77]

@Latzi die letzten Erkenntnisse dazu waren das das passiert wenn der dhcp lease ausläuft. Hast du „immer gleich ip geben“ aktiviert?

[Latzi]

@apollon77 ja, ist eingestellt

Edit: Mesh ist aktiv!

[apollon77]

@Latzi Dann keine IDee... Die FB gibt den Fehler zurück ...

[Latzi]

@apollon77 oje, schade. Trotzdem Danke

[Xyolyp]

@crunchip Ich habe das gleiche Problem wie du. Wenn der Adapter ein paar Tage läuft tut er nichts mehr mit dem Callmonitor. Anwesenheit funktioniert weiter aber der Callmonitor steigt aus.

[crunchip]

@Xyolyp nachdem ich heute Nacht, den Adapter kurzfristig auf debug gestellt hatte, funktioniert aktuell wieder alles, habe heute Nachmittag dann verschiedene Szenarien durchgetestet. Alle states werden aktualisiert. Mal sehen, wie lange.
Werde die Tage mal genauer beobachten, vllt auch einen Zusammenhang zu finden, wenn die Fritzbox alle paar Tage seitens Telekom aktualisiert wird.

[crunchip]

aktueller Stand der Dinge, Anruf bekommen, keine Ansage, folglich, es wurde wieder nicht aktualisiert.
Fritzbox Ereignisse durchgesehen, nichts negatives
Verbindung der Fritzbox/Internetanbieter, wurde auch nichts aktualisiert

• die schlechte Nachricht, tr-64 wurde wieder nirgends ein state aktualisiert, Stand/Zeitstempel, letzter Anruf von gestern
• die ganz schlechte Nachricht, nun hat auch der Fritzbox Adapter nicht aktualisiert! Selber Stand/Zeitstempel von gestern

[apollon77]

@crunchip Findest Du im Log irgendwas von dem adapter nach dem letzten Zeitstempel?

[apollon77]

@crunchip bzw versuch malden Fix bei dir manuell einzubauen

https://github.com/iobroker-community-adapters/ioBroker.tr-064/commit/17acbc4aca960ca911087b8830ace84e4dd5a49c

da hatte ich mal ne exception gesehn die ggf für sowas verantwortlich sein könnte

0 Apollon77 committed to iobroker-community-adapters/ioBroker.tr-064

fix

[wendy2702]

@crunchip sagte in tr-064 v3.1.x (Latest Repo) Diskussion:

@dslraser
Ich hatte ja den Fritzbox Adapter laufen, jedoch damals, glaub bei Umstellung auf den js-controller 2.x, warf der Fritzbox Adapter einige Fehler und bekam ihn nicht mehr zum laufen und da ich ihn eigentlich eh nicht in Verwendung hatte, habe ich ihn gelöscht.
Das gleich, mit dem alten (soef) tr-64, dieser lief ohne Probleme, bekam ich auch nicht mehr zum laufen, mit dem Controller Update, daher der Wechsel auf den Community. Dieser lief genauso bescheiden, wie der Jetzige tr-64.
Zeitgleich hatte ich diese nicht laufen.

Hast du nur die Instanz nicht laufen aber vielleicht noch eine Instanz und/oder die Adapter installiert?

Ich glaube das ist es was @dslraser meint.

Bei mir läuft der Adapter inklusive Ansage Script seit erscheinen Problemlos.

[dslraser]

@wendy2702
ja, so meinte ich das. Probleme hatte ich, als zwei Varianten installiert waren, mit Instanzen, auch wenn nur eine Instanz aktiviert war. Aktuell habe ich nur den 3.4.1 installiert bzw. eine Instanz davon und die ist aktiv. Es gibt keine weitere (auch keine deaktivierte) Instanz.
Aber trotzdem weiß ich nicht ob es da einen Zusammenhang gibt.

[crunchip]

@apollon77 Im heutigen log taucht gar nichts auf, weder tr-64 noch fritzbox.
Das ist das log, vom letzten Test/Anruf gestern

2020-02-19 13:13:47.784 - info: fritzbox.0 (3268) data from 192.168.178.1: 19.02.20 13:13:47;RING;0;xxxxxxxx;xxxx;SIP0;
2020-02-19 13:13:48.827 - info: sayit.0 (3070) saying: xxxxxxx ruft gerade an.
2020-02-19 13:13:49.073 - info: sayit.0 (3070) Set "chromecast.0.Google_Home_mini.player.announcement to {"url":"http://10.1.1.10:8082/state/sayit.0.tts.mp3","volume":60}
2020-02-19 13:14:03.757 - info: fritzbox.0 (3268) data from 192.168.178.1: 19.02.20 13:14:03;DISCONNECT;0;0;
2020-02-19 13:16:00.022 - info: host.IoBroker instance system.adapter.dwd.0 started with pid 11203
2020-02-19 13:16:05.236 - info: host.IoBroker instance system.adapter.dwd.0 terminated with code 0 (NO_ERROR)
2020-02-19 13:18:56.478 - info: info.0 (1703) Popup news was read...
2020-02-19 13:20:00.083 - info: host.IoBroker instance system.adapter.weatherunderground.0 started with pid 12442
2020-02-19 13:20:08.684 - info: host.IoBroker instance system.adapter.weatherunderground.0 terminated with code 0 (NO_ERROR)
2020-02-19 13:23:17.103 - info: fritzbox.0 (3268) data from 192.168.178.1: 19.02.20 13:23:17;RING;0;xxxxxxx;981400;SIP0;
2020-02-19 13:23:18.173 - info: sayit.0 (3070) saying: xxxxxxxxx ruft gerade an.
2020-02-19 13:23:18.378 - info: sayit.0 (3070) Set "chromecast.0.Google_Home_mini.player.announcement to {"url":"http://10.1.1.10:8082/state/sayit.0.tts.mp3","volume":60}
2020-02-19 13:23:25.692 - info: fritzbox.0 (3268) data from 192.168.178.1: 19.02.20 13:23:25;DISCONNECT;0;0;
2020-02-19 13:24:07.593 - info: fritzbox.0 (3268) data from 192.168.178.1: 19.02.20 13:24:07;CALL;0;0;xxxxx;xxxxxxxx;SIP0;
2020-02-19 13:24:38.693 - info: fritzbox.0 (3268) data from 192.168.178.1: 19.02.20 13:24:38;DISCONNECT;0;0;
2020-02-19 13:27:59.752 - info: fritzbox.0 (3268) data from 192.168.178.1: 19.02.20 13:27:59;CALL;0;0;xxxxx;xxxxxxxxx;SIP0;
2020-02-19 13:28:18.208 - info: fritzbox.0 (3268) data from 192.168.178.1: 19.02.20 13:28:18;CONNECT;0;0;xxxxxxxxx;
2020-02-19 13:28:26.370 - info: fritzbox.0 (3268) data from 192.168.178.1: 19.02.20 13:28:26;DISCONNECT;0;6;

hier nach dem cronjob

2020-02-20 00:01:00.016 - info: tr-064.0 (3240) Scheduled restart.
2020-02-20 00:01:00.041 - info: tr-064.0 (3240) terminating
2020-02-20 00:01:00.045 - info: tr-064.0 (3240) Terminated (START_IMMEDIATELY_AFTER_STOP): Without reason
2020-02-20 00:01:00.620 - error: host.IoBroker instance system.adapter.tr-064.0 terminated with code 156 (156)
2020-02-20 00:01:00.620 - info: host.IoBroker Restart adapter system.adapter.tr-064.0 because enabled
2020-02-20 00:01:01.678 - info: host.IoBroker instance system.adapter.tr-064.0 started with pid 21837
2020-02-20 00:01:04.336 - info: tr-064.0 (21837) starting. Version 3.1.4 in /opt/iobroker/node_modules/iobroker.tr-064, node: v10.19.0