Presence: could not execute ctlmgr_ctl

[andre]

Hallo zusammen,

seit einiger Zeit habe ich in unregelmäßigen Abständen ein Problem mit dem Presence Modul auf der Fritzbox 7390. Nach einiger Zeit steht im Log zunächst vereinzelt:

Code Auswählen Erweitern


2014.01.05 18:33:39 2: PRESENCE: error while processing device a - could not execute ctlmgr_ctl

oder

Code Auswählen Erweitern


2014.01.05 19:22:19 2: PRESENCE: error while processing device b - could not execute ctlmgr_ctl (cached)


Nach einiger Zeit (ca. 2 Stunden) wird diese Meldung quasi jede Minute ins Log geschrieben (immer das eine oder das andere). Auch erkennt Presence dann nicht mehr, ob jemand da ist oder nicht.

In einem letzten Block im Log steht dann folgendes, wonach sich das die Fehlermeldung auch nicht mehr kommt, jedoch die Anwesenheit auch trotzdem weiterhin nicht erkannt/aktualisiert wird:

Code Auswählen Erweitern

2014.01.06 06:18:25 2: PRESENCE: error while processing device a - could not execute ctlmgr_ctl
2014.01.06 06:19:00 2: PRESENCE: error while processing device a - could not execute ctlmgr_ctl
2014.01.06 06:19:35 2: PRESENCE: error while processing device a - could not execute ctlmgr_ctl
2014.01.06 06:20:10 1: Cannot fork: Cannot allocate memory


Hat dafür evtl. jemand einen Rat für mich? Ich nutze die neuste Version aus dem SVN von Presence.

Viele Grüße
André

[Markus Bloch]

Hallo Andre,

kannst du bitte bei dieser PRESENCE Definition das Attribut "verbose" auf 5 stellen und dann nochmal beim Auftreten dieses Fehlers die entsprechenden Log-Meldungen posten?

Vielen Dank

Gruß
Markus

[andre]

Hallo Markus,

danke für Deine Antwort.
Ich habe in der noch laufenden Instanz das Verbose Level geändert, aber es passiert gar nichts mehr (scheinbar ist das Modul komplett abgestürzt?!).

Daher werde ich jetzt FHEM neu starten und den verbose level auf 5 umstellen. Sobald der Fehler wieder kommt (kann einige Tage dauern), melde ich mich wieder.

Viele Grüße
André

[andre]

Hallo Markus,

jetzt war es wieder soweit, dass der Fehler auftrat. Hier nun die Auszüge aus dem Log.

Direkt bevor das "cannot allocate memory" kam, waren folgende Einträge:

Code Auswählen Erweitern


...
2014.01.11 07:21:56 5: PRESENCE_DoLocalFritzBoxScan: Andre|AndreHeuersiPhone|0|0
2014.01.11 07:21:56 5: PRESENCE_DoLocalFritzBoxScan: try checking Andre as device AndreHeuersiPhone with cached number 1
2014.01.11 07:21:56 5: PRESENCE (Andre) - cached device name () does not match expected name (AndreHeuersiPhone). perform a full scan
2014.01.11 07:21:56 5: PRESENCE (Andre) - ctlmgr_ctl (getting device count) returned:
2014.01.11 07:21:56 5: PRESENCE_ProcessLocalScan: Andre|0|error|could not execute ctlmgr_ctl
2014.01.11 07:21:56 2: PRESENCE: error while processing device Andre - could not execute ctlmgr_ctl
2014.01.11 07:22:31 5: PRESENCE_DoLocalFritzBoxScan: Andre|AndreHeuersiPhone|0|0
2014.01.11 07:22:31 5: PRESENCE_DoLocalFritzBoxScan: try checking Andre as device AndreHeuersiPhone with cached number 1
2014.01.11 07:22:31 5: PRESENCE (Andre) - cached device name () does not match expected name (AndreHeuersiPhone). perform a full scan
2014.01.11 07:22:31 5: PRESENCE (Andre) - ctlmgr_ctl (getting device count) returned:
2014.01.11 07:22:31 5: PRESENCE_ProcessLocalScan: Andre|0|error|could not execute ctlmgr_ctl
2014.01.11 07:22:31 2: PRESENCE: error while processing device Andre - could not execute ctlmgr_ctl
2014.01.11 07:23:06 5: PRESENCE_DoLocalFritzBoxScan: Andre|AndreHeuersiPhone|0|0
2014.01.11 07:23:06 5: PRESENCE_DoLocalFritzBoxScan: try checking Andre as device AndreHeuersiPhone with cached number 1
2014.01.11 07:23:06 5: PRESENCE (Andre) - cached device name () does not match expected name (AndreHeuersiPhone). perform a full scan
2014.01.11 07:23:06 5: PRESENCE (Andre) - ctlmgr_ctl (getting device count) returned:
2014.01.11 07:23:07 5: PRESENCE_ProcessLocalScan: Andre|0|error|could not execute ctlmgr_ctl
2014.01.11 07:23:07 2: PRESENCE: error while processing device Andre - could not execute ctlmgr_ctl
2014.01.11 07:23:42 1: Cannot fork: Cannot allocate memory


Interessaterweise sind da auch nur Einträge zu meinem Handy drin und nicht zu dem Handy meiner Freundin, obwohl ihr Handy auch darüber abgefragt wird.

Ihr Handy taucht das letzte mal hier auf:

Code Auswählen Erweitern


...
2014.01.11 00:24:07 5: PRESENCE (Annika) - checking with cached number the speed state (24)
2014.01.11 00:24:07 5: PRESENCE (Annika) - ctlmgr_ctl (cached: 24) returned: 0
2014.01.11 00:24:07 5: PRESENCE_ProcessLocalScan: Annika|0|absent|24
2014.01.11 00:24:42 5: PRESENCE_DoLocalFritzBoxScan: Andre|AndreHeuersiPhone|0|0
2014.01.11 00:24:42 5: PRESENCE_DoLocalFritzBoxScan: try checking Andre as device AndreHeuersiPhone with cached number 1
2014.01.11 00:24:42 5: PRESENCE (Andre) - cached device name () does not match expected name (AndreHeuersiPhone). perform a full scan
2014.01.11 00:24:42 5: PRESENCE (Andre) - ctlmgr_ctl (getting device count) returned:
2014.01.11 00:24:42 5: PRESENCE_DoLocalFritzBoxScan: Annika|iPhonevonAnnika|0|0
2014.01.11 00:24:42 5: PRESENCE_DoLocalFritzBoxScan: try checking Annika as device iPhonevonAnnika with cached number 24
2014.01.11 00:24:42 5: PRESENCE (Annika) - cached device name () does not match expected name (iPhonevonAnnika). perform a full scan
2014.01.11 00:24:42 5: PRESENCE (Annika) - ctlmgr_ctl (getting device count) returned:
2014.01.11 00:24:42 5: PRESENCE_ProcessLocalScan: Andre|0|error|could not execute ctlmgr_ctl
2014.01.11 00:24:42 2: PRESENCE: error while processing device Andre - could not execute ctlmgr_ctl
2014.01.11 00:24:42 5: PRESENCE_ProcessLocalScan: Annika|0|error|could not execute ctlmgr_ctl
2014.01.11 00:24:42 2: PRESENCE: error while processing device Annika - could not execute ctlmgr_ctl
2014.01.11 00:25:17 5: PRESENCE_DoLocalFritzBoxScan: Andre|AndreHeuersiPhone|0|0
2014.01.11 00:25:17 5: PRESENCE_DoLocalFritzBoxScan: try checking Andre as device AndreHeuersiPhone with cached number 1
2014.01.11 00:25:17 5: PRESENCE_DoLocalFritzBoxScan: Annika|iPhonevonAnnika|0|0
2014.01.11 00:25:17 5: PRESENCE_DoLocalFritzBoxScan: try checking Annika as device iPhonevonAnnika with cached number 24
2014.01.11 00:25:17 5: PRESENCE_ExecuteFritzBoxCMD: (Annika) - ctlmgr_ctl is locked. waiting 3 seconds...
2014.01.11 00:25:17 5: PRESENCE (Andre) - checking with cached number the speed state (1)
2014.01.11 00:25:17 5: PRESENCE (Andre) - ctlmgr_ctl (cached: 1) returned:
2014.01.11 00:25:17 5: PRESENCE_ProcessLocalScan: Andre|0|error|could not execute ctlmgr_ctl (cached)
2014.01.11 00:25:17 2: PRESENCE: error while processing device Andre - could not execute ctlmgr_ctl (cached)
2014.01.11 00:25:20 5: PRESENCE (Annika) - checking with cached number the speed state (24)
2014.01.11 00:25:20 5: PRESENCE (Annika) - ctlmgr_ctl (cached: 24) returned: 0
2014.01.11 00:25:20 5: PRESENCE_ProcessLocalScan: Annika|0|absent|24


Das erste mal (in dieser "Testreihe") taucht das cannot execute an folgender Stelle auf:

Code Auswählen Erweitern


...
2014.01.10 21:09:25 5: PRESENCE_DoLocalFritzBoxScan: try checking Annika as device iPhonevonAnnika with cached number 24
2014.01.10 21:09:25 5: PRESENCE_ExecuteFritzBoxCMD: (Annika) - ctlmgr_ctl is locked. waiting 3 seconds...
2014.01.10 21:09:26 5: PRESENCE (Andre) - checking with cached number the speed state (1)
2014.01.10 21:09:26 5: PRESENCE (Andre) - ctlmgr_ctl (cached: 1) returned: 0
2014.01.10 21:09:26 5: PRESENCE_ProcessLocalScan: Andre|0|absent|1
2014.01.10 21:09:29 5: PRESENCE (Annika) - checking with cached number the speed state (24)
2014.01.10 21:09:29 5: PRESENCE (Annika) - ctlmgr_ctl (cached: 24) returned: 0
2014.01.10 21:09:29 5: PRESENCE_ProcessLocalScan: Annika|0|absent|24
2014.01.10 21:10:00 5: PRESENCE_DoLocalFritzBoxScan: Andre|AndreHeuersiPhone|0|0
2014.01.10 21:10:00 5: PRESENCE_DoLocalFritzBoxScan: try checking Andre as device AndreHeuersiPhone with cached number 1
2014.01.10 21:10:00 5: PRESENCE_DoLocalFritzBoxScan: Annika|iPhonevonAnnika|0|0
2014.01.10 21:10:00 5: PRESENCE_DoLocalFritzBoxScan: try checking Annika as device iPhonevonAnnika with cached number 24
2014.01.10 21:10:00 5: PRESENCE_ExecuteFritzBoxCMD: (Annika) - ctlmgr_ctl is locked. waiting 3 seconds...
2014.01.10 21:10:00 5: PRESENCE (Andre) - checking with cached number the speed state (1)
2014.01.10 21:10:00 5: PRESENCE (Andre) - ctlmgr_ctl (cached: 1) returned: 0
2014.01.10 21:10:00 5: PRESENCE_ProcessLocalScan: Andre|0|absent|1
2014.01.10 21:10:03 5: PRESENCE (Annika) - checking with cached number the speed state (24)
2014.01.10 21:10:03 5: PRESENCE (Annika) - ctlmgr_ctl (cached: 24) returned: 0
2014.01.10 21:10:03 5: PRESENCE_ProcessLocalScan: Annika|0|absent|24
2014.01.10 21:10:35 5: PRESENCE_DoLocalFritzBoxScan: Andre|AndreHeuersiPhone|0|0
2014.01.10 21:10:35 5: PRESENCE_DoLocalFritzBoxScan: try checking Andre as device AndreHeuersiPhone with cached number 1
2014.01.10 21:10:35 1: 192.168.2.101:1000 disconnected, waiting to reappear
2014.01.10 21:10:35 5: PRESENCE_DoLocalFritzBoxScan: Annika|iPhonevonAnnika|0|0
2014.01.10 21:10:35 5: PRESENCE_DoLocalFritzBoxScan: try checking Annika as device iPhonevonAnnika with cached number 24
2014.01.10 21:10:35 5: PRESENCE_ExecuteFritzBoxCMD: (Annika) - ctlmgr_ctl is locked. waiting 3 seconds...
2014.01.10 21:10:35 5: PRESENCE (Andre) - checking with cached number the speed state (1)
2014.01.10 21:10:35 5: PRESENCE (Andre) - ctlmgr_ctl (cached: 1) returned:
2014.01.10 21:10:35 1: HMLAN_Parse: LCARS_Kommunikationsphalanx new condition disconnected
2014.01.10 21:10:35 1: 192.168.2.101:1000 reappeared (LCARS_Kommunikationsphalanx)
2014.01.10 21:10:35 1: HMLAN_Parse: LCARS_Kommunikationsphalanx new condition init
2014.01.10 21:10:35 1: HMLAN_Parse: LCARS_Kommunikationsphalanx new condition ok
2014.01.10 21:10:36 5: PRESENCE_ProcessLocalScan: Andre|0|error|could not execute ctlmgr_ctl (cached)
2014.01.10 21:10:36 2: PRESENCE: error while processing device Andre - could not execute ctlmgr_ctl (cached)
2014.01.10 21:10:38 5: PRESENCE (Annika) - cached device name () does not match expected name (iPhonevonAnnika). perform a full scan
2014.01.10 21:10:38 5: PRESENCE (Annika) - ctlmgr_ctl (getting device count) returned:
2014.01.10 21:10:38 5: PRESENCE_ProcessLocalScan: Annika|0|error|could not execute ctlmgr_ctl
...


Falls Du noch weitere Ausschnitte benötigst, melde Dich einfach :-/

Viele Grüße
André

[Markus Bloch]

Hallo andre,

was ich da sehe ist, dass ctlmgr_ctl massig keine Antwort mehr liefert und irgendwann beim Versuch wieder einen Check durchzuführen der Arbeitsspeicher der FritzBox erschöpft ist.

Ich glaube, dass deine FritzBox mit deinem FHEM überlastet zu sein scheint.

Was sagen denn die Grafiken auf der FritzBox Web-Oberfläche unter "System" => "Energiemonitor" => "Statistik"?

Viele Grüße

Markus

[andre]

Hallo Markus,

ok, ich verstehe das potentielle Problem. Die Auslastung ist aber m.E. nicht allzu hoch.
Leider ist FHEM jetzt auch komplett abgestürzt. Ich habe dann die FB neu gestartet.

Im Anhang findest Du den aktuellen Graphen...

Irgendwie wirkt die FB m.E. nicht überlastet, oder?

Wenn ich mir mit Hilfe von top auf der FB mal über ein paar Minuten den perl Prozess angucke, fällt der auch nicht unbedingt auf (z.B. durch andauerende Last oder so). Zwischendurch hat der Prozess mal ca. 20-30% CPU Last aber das war es dann auch

Viele Grüße
André

[Markus Bloch]

Hallo andre,

ich hatte das auch eher auf die RAM Auslastung bezogen und weniger auf die CPU Belastung.

Kannst du mir den zweiten Graphen schicken?

Danke

Gruß
Markus

[andre]

Hallo Markus,

alles klar

Hab ich angehängt. Ich habe so im Gefühl, dass die Auslastung die ganze Zeit konstant ansteigt...(((

Gruß
André