FB_CALLLIST: Status einiger Gespräche fehlerhaft

[FunkOdyssey]

Hallo, ich habe in meiner FB_CALLLIST-Übersicht seit ein paar Tagen immer wieder ältere Anrufe, bei denen in der Spalte "Dauer" der Text "läuft" angezeigt wird.
Die Anrufe laufen aber nicht mehr.

Kennt jemand das Problem und hat einen Tipp für mich?

Danke.

[Markus Bloch]

Hi,

in so einem Fall scheint das Event "disconnect" nicht von FB_CALLLIST verarbeitet worden sein. Nutzt du in deiner FB_CALLMONITOR-Definition die Attribute event-on-change-reading/event-on-update-reading?

Gruß
Markus

[FunkOdyssey]

Guter Hinweis, aber ich habe keine "spannenden" Attribute im CallMonitor angelegt.

Code Auswählen Erweitern

Attributes:
   fritzbox-remote-phonebook 1
   fritzbox-remote-phonebook-via tr064
   fritzbox-user benutzername
   icon       it_telephone
   local-area-code 12345
   reverse-search phonebook
   stateFormat external_name (external_number)


Ich habe mal ein Log für den CallMonitor angelegt und werde das nun beobachten.

[Markus Bloch]

Am besten mal FB_CALLLIST und FB_CALLMONITOR auf verbose 5 setzen und dann sollte der Fall wieder auftreten einmal die Logs studieren oder alternativ mir auf einem privaten Kanal schicken.

Gruß
Markus

[FunkOdyssey]

Es hat ein wenig gedauert, aber hier die Logs von einigen Anrufen. Ich habe im Log ein paar Kommentare ergänzt:

FbCallMonitor

Code Auswählen Erweitern


Erfolgloser Anrufversuch. Spielt hier keine Rolle.
================================================================
2016-12-20_14:33:01 FbCallMonitor event: call
2016-12-20_14:33:01 FbCallMonitor direction: outgoing
2016-12-20_14:33:01 FbCallMonitor internal_connection: DECT_1
2016-12-20_14:33:01 FbCallMonitor call_id: 1
2016-12-20_14:33:01 FbCallMonitor external_name: Vorname Nachname
2016-12-20_14:33:01 FbCallMonitor internal_number: 456789
2016-12-20_14:33:01 FbCallMonitor external_connection: SIP0
2016-12-20_14:33:01 FbCallMonitor external_number: 012345678

2016-12-20_14:33:04 FbCallMonitor event: disconnect
2016-12-20_14:33:04 FbCallMonitor call_id: 1
2016-12-20_14:33:04 FbCallMonitor call_duration: 0
2016-12-20_14:33:04 FbCallMonitor direction: outgoing
2016-12-20_14:33:04 FbCallMonitor internal_connection: DECT_1
2016-12-20_14:33:04 FbCallMonitor internal_number: 456789
2016-12-20_14:33:04 FbCallMonitor external_connection: SIP0
2016-12-20_14:33:04 FbCallMonitor external_number: 012345678
2016-12-20_14:33:04 FbCallMonitor external_name: Vorname Nachname

DIESER ANRUF IST ANSCHEINEND IMMER NOCH AKTIV
================================================================
2016-12-20_14:34:40 FbCallMonitor event: call
2016-12-20_14:34:40 FbCallMonitor direction: outgoing
2016-12-20_14:34:40 FbCallMonitor internal_connection: DECT_1
2016-12-20_14:34:40 FbCallMonitor call_id: 1
2016-12-20_14:34:40 FbCallMonitor external_name: Vorname Nachname
2016-12-20_14:34:40 FbCallMonitor internal_number: 456789
2016-12-20_14:34:40 FbCallMonitor external_connection: SIP0
2016-12-20_14:34:40 FbCallMonitor external_number: 012345678

2016-12-20_14:34:57 FbCallMonitor event: connect
2016-12-20_14:34:57 FbCallMonitor direction: outgoing
2016-12-20_14:34:57 FbCallMonitor internal_connection: DECT_1
2016-12-20_14:34:57 FbCallMonitor call_id: 1
2016-12-20_14:34:57 FbCallMonitor external_name: Vorname Nachname
2016-12-20_14:34:57 FbCallMonitor internal_number: 456789
2016-12-20_14:34:57 FbCallMonitor external_connection: SIP0
2016-12-20_14:34:57 FbCallMonitor external_number: 012345678

2016-12-20_14:36:13 FbCallMonitor event: disconnect
2016-12-20_14:36:13 FbCallMonitor call_id: 1
2016-12-20_14:36:13 FbCallMonitor internal_connection: DECT_1
2016-12-20_14:36:13 FbCallMonitor direction: outgoing
2016-12-20_14:36:13 FbCallMonitor call_duration: 77
2016-12-20_14:36:13 FbCallMonitor external_name: Vorname Nachname
2016-12-20_14:36:13 FbCallMonitor external_connection: SIP0
2016-12-20_14:36:13 FbCallMonitor external_number: 012345678
2016-12-20_14:36:13 FbCallMonitor internal_number: 456789

DIESER ANRUF WURDE WIEDER RICHTIG ANGEZEIGT
================================================================
2016-12-20_14:47:49 FbCallMonitor event: ring
2016-12-20_14:47:49 FbCallMonitor call_id: 0
2016-12-20_14:47:49 FbCallMonitor internal_number: 456789
2016-12-20_14:47:49 FbCallMonitor external_connection: SIP0
2016-12-20_14:47:49 FbCallMonitor external_number: 01234-987654
2016-12-20_14:47:49 FbCallMonitor direction: incoming
2016-12-20_14:47:49 FbCallMonitor external_name: Donald Duck

2016-12-20_14:47:55 FbCallMonitor event: connect
2016-12-20_14:47:55 FbCallMonitor external_connection: SIP0
2016-12-20_14:47:55 FbCallMonitor external_number: 01234-987654
2016-12-20_14:47:55 FbCallMonitor internal_number: 456789
2016-12-20_14:47:55 FbCallMonitor external_name: Donald Duck
2016-12-20_14:47:55 FbCallMonitor call_id: 0
2016-12-20_14:47:55 FbCallMonitor internal_connection: DECT_1
2016-12-20_14:47:55 FbCallMonitor direction: incoming

2016-12-20_14:56:39 FbCallMonitor event: disconnect
2016-12-20_14:56:39 FbCallMonitor call_id: 0
2016-12-20_14:56:39 FbCallMonitor direction: incoming
2016-12-20_14:56:39 FbCallMonitor internal_connection: DECT_1
2016-12-20_14:56:39 FbCallMonitor call_duration: 524
2016-12-20_14:56:39 FbCallMonitor external_name: Donald Duck
2016-12-20_14:56:39 FbCallMonitor internal_number: 456789
2016-12-20_14:56:39 FbCallMonitor external_connection: SIP0
2016-12-20_14:56:39 FbCallMonitor external_number: 01234-987654




FB_CALLLIST (aus fhem.log)

Code Auswählen Erweitern


Erfolgloser Anrufversuch. Spielt hier keine Rolle.
================================================================
2016.12.20 14:33:01 5: FB_CALLMONITOR (FbCallMonitor) - received data: 20.12.16 14:33:01;CALL;1;10;456789;5678;SIP0
2016.12.20 14:33:01 4: FB_CALLMONITOR (FbCallMonitor) - using internal phonebook for reverse search of 012345678
2016.12.20 14:33:01 4: FB_CALLMONITOR (FbCallMonitor) - reverse search returned: Vorname Nachname
2016.12.20 14:33:01 4: FB_CALLLIST (FbCallList) - start processing event call for Call-ID 1
2016.12.20 14:33:01 5: FB_CALLLIST (FbCallList) - created new data hash: HASH(0x62f1038)
2016.12.20 14:33:01 4: FB_CALLLIST (FbCallList) - cleaning up call list
2016.12.20 14:33:01 5: FB_CALLLIST (FbCallList) - deleting old call 1481740747.15898
2016.12.20 14:33:02 5: FB_CALLLIST (FbCallList) - inform all FHEMWEB clients
2016.12.20 14:33:02 5: FB_CALLLIST (FbCallList) - start dumping of list to file
2016.12.20 14:33:02 5: FB_CALLLIST (FbCallList) - found Compress::Zlib module, compressing dump
2016.12.20 14:33:02 5: FB_CALLLIST (FbCallList) - saving list dump: xxxx
2016.12.20 14:33:04 5: FB_CALLMONITOR (FbCallMonitor) - received data: 20.12.16 14:33:04;DISCONNECT;1;0
2016.12.20 14:33:04 4: FB_CALLLIST (FbCallList) - start processing event disconnect for Call-ID 1
2016.12.20 14:33:04 5: FB_CALLLIST (FbCallList) - found old data hash: HASH(0x62f1038)
2016.12.20 14:33:04 5: FB_CALLLIST (FbCallList) - processed disconnect event for call id 1
2016.12.20 14:33:04 4: FB_CALLLIST (FbCallList) - cleaning up call list
2016.12.20 14:33:04 5: FB_CALLLIST (FbCallList) - inform all FHEMWEB clients
2016.12.20 14:33:04 5: FB_CALLLIST (FbCallList) - start dumping of list to file
2016.12.20 14:33:04 5: FB_CALLLIST (FbCallList) - found Compress::Zlib module, compressing dump
2016.12.20 14:33:04 5: FB_CALLLIST (FbCallList) - saving list dump: xxxx

DIESER ANRUF IST ANSCHEINEND IMMER NOCH AKTIV
================================================================
2016.12.20 14:34:40 5: FB_CALLMONITOR (FbCallMonitor) - received data: 20.12.16 14:34:40;CALL;1;10;456789;5678;SIP0
2016.12.20 14:34:40 4: FB_CALLMONITOR (FbCallMonitor) - using internal phonebook for reverse search of 012345678
2016.12.20 14:34:40 4: FB_CALLMONITOR (FbCallMonitor) - reverse search returned: Vorname Nachname
2016.12.20 14:34:40 4: FB_CALLLIST (FbCallList) - start processing event call for Call-ID 1
2016.12.20 14:34:40 5: FB_CALLLIST (FbCallList) - created new data hash: HASH(0x62e1a08)
2016.12.20 14:34:40 4: FB_CALLLIST (FbCallList) - cleaning up call list
2016.12.20 14:34:40 5: FB_CALLLIST (FbCallList) - deleting old call 1481747275.60242
2016.12.20 14:34:41 5: FB_CALLLIST (FbCallList) - inform all FHEMWEB clients
2016.12.20 14:34:41 5: FB_CALLLIST (FbCallList) - start dumping of list to file
2016.12.20 14:34:41 5: FB_CALLLIST (FbCallList) - found Compress::Zlib module, compressing dump
2016.12.20 14:34:41 5: FB_CALLLIST (FbCallList) - saving list dump: xxxx
2016.12.20 14:34:57 5: FB_CALLMONITOR (FbCallMonitor) - received data: 20.12.16 14:34:57;CONNECT;1;10;5678
2016.12.20 14:34:57 4: FB_CALLLIST (FbCallList) - start processing event connect for Call-ID 1
2016.12.20 14:34:57 5: FB_CALLLIST (FbCallList) - found old data hash: HASH(0x3d2be68)
2016.12.20 14:34:57 5: FB_CALLLIST (FbCallList) - processed connect event for call id 1
2016.12.20 14:34:57 4: FB_CALLLIST (FbCallList) - cleaning up call list
2016.12.20 14:34:57 5: FB_CALLLIST (FbCallList) - inform all FHEMWEB clients
2016.12.20 14:34:57 5: FB_CALLLIST (FbCallList) - start dumping of list to file
2016.12.20 14:34:57 5: FB_CALLLIST (FbCallList) - found Compress::Zlib module, compressing dump
2016.12.20 14:34:57 5: FB_CALLLIST (FbCallList) - saving list dump: xxxx
2016.12.20 14:36:13 5: FB_CALLMONITOR (FbCallMonitor) - received data: 20.12.16 14:36:13;DISCONNECT;1;77
2016.12.20 14:36:13 4: FB_CALLLIST (FbCallList) - start processing event disconnect for Call-ID 1
2016.12.20 14:36:13 5: FB_CALLLIST (FbCallList) - found old data hash: HASH(0x3d2be68)
2016.12.20 14:36:13 5: FB_CALLLIST (FbCallList) - processed disconnect event for call id 1
2016.12.20 14:36:13 4: FB_CALLLIST (FbCallList) - cleaning up call list
2016.12.20 14:36:14 5: FB_CALLLIST (FbCallList) - inform all FHEMWEB clients
2016.12.20 14:36:14 5: FB_CALLLIST (FbCallList) - start dumping of list to file
2016.12.20 14:36:14 5: FB_CALLLIST (FbCallList) - found Compress::Zlib module, compressing dump
2016.12.20 14:36:14 5: FB_CALLLIST (FbCallList) - saving list dump: xxx

DIESER ANRUF WURDE WIEDER RICHTIG ANGEZEIGT
================================================================
2016.12.20 14:47:49 5: FB_CALLMONITOR (FbCallMonitor) - received data: 20.12.16 14:47:49;RING;0;01234-987654;456789;SIP0
2016.12.20 14:47:49 4: FB_CALLMONITOR (FbCallMonitor) - using internal phonebook for reverse search of 01234-987654
2016.12.20 14:47:49 4: FB_CALLMONITOR (FbCallMonitor) - reverse search returned: Donald Duck
2016.12.20 14:47:49 4: FB_CALLLIST (FbCallList) - start processing event ring for Call-ID 0
2016.12.20 14:47:49 5: FB_CALLLIST (FbCallList) - created new data hash: HASH(0x5c31620)
2016.12.20 14:47:49 4: FB_CALLLIST (FbCallList) - cleaning up call list
2016.12.20 14:47:49 5: FB_CALLLIST (FbCallList) - deleting old call 1481786284.486
2016.12.20 14:47:50 5: FB_CALLLIST (FbCallList) - inform all FHEMWEB clients
2016.12.20 14:47:50 5: FB_CALLLIST (FbCallList) - start dumping of list to file
2016.12.20 14:47:50 5: FB_CALLLIST (FbCallList) - found Compress::Zlib module, compressing dump
2016.12.20 14:47:50 5: FB_CALLLIST (FbCallList) - saving list dump: xxxx
2016.12.20 14:47:55 5: FB_CALLMONITOR (FbCallMonitor) - received data: 20.12.16 14:47:55;CONNECT;0;10;01234-987654
2016.12.20 14:47:55 4: FB_CALLLIST (FbCallList) - start processing event connect for Call-ID 0
2016.12.20 14:47:55 5: FB_CALLLIST (FbCallList) - found old data hash: HASH(0x5c31620)
2016.12.20 14:47:55 5: FB_CALLLIST (FbCallList) - processed connect event for call id 0
2016.12.20 14:47:55 4: FB_CALLLIST (FbCallList) - cleaning up call list
2016.12.20 14:47:55 5: FB_CALLLIST (FbCallList) - inform all FHEMWEB clients
2016.12.20 14:47:55 5: FB_CALLLIST (FbCallList) - start dumping of list to file
2016.12.20 14:47:55 5: FB_CALLLIST (FbCallList) - found Compress::Zlib module, compressing dump
2016.12.20 14:47:55 5: FB_CALLLIST (FbCallList) - saving list dump: xxxx
2016.12.20 14:56:39 5: FB_CALLMONITOR (FbCallMonitor) - received data: 20.12.16 14:56:39;DISCONNECT;0;524
2016.12.20 14:56:39 4: FB_CALLLIST (FbCallList) - start processing event disconnect for Call-ID 0
2016.12.20 14:56:39 5: FB_CALLLIST (FbCallList) - found old data hash: HASH(0x5c31620)
2016.12.20 14:56:39 5: FB_CALLLIST (FbCallList) - processed disconnect event for call id 0
2016.12.20 14:56:39 4: FB_CALLLIST (FbCallList) - cleaning up call list
2016.12.20 14:56:39 5: FB_CALLLIST (FbCallList) - inform all FHEMWEB clients
2016.12.20 14:56:39 5: FB_CALLLIST (FbCallList) - start dumping of list to file
2016.12.20 14:56:39 5: FB_CALLLIST (FbCallList) - found Compress::Zlib module, compressing dump
2016.12.20 14:56:39 5: FB_CALLLIST (FbCallList) - saving list dump: xxxx


[Markus Bloch]

Da ist noch eine Datenleiche im internen Hash von FB_CALLLIST vorhanden. Für mal bitte folgenden Befehl in der Web-Oberfläche aus:

Code Auswählen Erweitern

{Dumper($defs{FbCallList})}

Die große Frage ist nun, wieso existiert da eine Leiche? normalerweise werden die Hashes gelöscht, sobald ein Disconnect-Event auftritt. Offenbar scheint dort ein Gespräch hängen geblieben zu sein und dieses findet er dann mal und mal nicht (Perl-Eigenart).

Ich werde dazu noch einen zusätzlichen Schutz vor solchen verwaisten Einträgen einbauen.

Vielen Dank

Gruß
Markus

[FunkOdyssey]

Danke. Benötigst du den Dump? Oder was soll ich damit machen?



Ich habe neuerdings relativ oft diese "Leichen" in der Liste.
Merkwürdigerweise (so habe ich das in Erinnerung) habe ich aber immer NUR EINEN verwaisten Eintrag in der ganzen Liste.
Ich kann mich nicht daran erinnern, dass in der Anrufliste zwei Einträge mit der Anzeige "läuft" vorhanden sind.



Ich nutze die aktuelle Konfiguration schon seit Monaten in unveränderter Form. Der Fehler ist irgendwann einfach aufgetreten. So wie es immer ist mit EDV-Bugs

[Markus Bloch]

Ja, den Dump bräuchte ich. Würde gerne verstehen in welchen Zustand der Eintrag ist.

Ich werde aber generell eine Vorkehrung einbauen, solche Leichen zu löschen.

Gruß
Markus

[FunkOdyssey]

Du solltest nun Post haben.
Diesmal hatte ich kein Bock darauf, die Inhalte zu anonymisieren.

[Markus Bloch]

Kann ich verstehen.

[Markus Bloch]

Ich habe nun eine Änderung eingecheckt, welche in einem solchen Fall, das verwaiste Gespräch als beendet markiert und dann das neue Gespräch korrekt anlegt. Da in diesem Fall das disconnect fehlt, wird keine Gesprächsdauer angezeigt. Gibt es morgen via update.

Im Log taucht in einem solchen Fall die Meldung "found running call with same call id" auf. Bitte in nächster Zeit mal beobachten. Solltest du diese Meldung im Log finden, bitte mal die vorherigen Gespräche bis kurz nach dieser Logmeldung nochmal posten oder mir schicken, damit wir sehen können, warum das vorherige Gespräch nicht als beendet erkannt wird. Am besten die Loglevels für CALLLIST und CALLLMONITOR bis auf weiteres erstmal auf 5 lassen.

Vielen Dank

Gruß
Markus

[FunkOdyssey]

Kurzer Zwischenstand:

Ich hatte am 21.12.2016 (am Tag nach deinem Fix) einen einzigen Eintrag "found running call with same call id" im FHEM Log.
Seitdem ist nie wieder etwas aufgetreten. Ich habe somit heute das Verbose-Level wieder runtergedreht.

Vielen Dank für deine Unterstützung.