Hi,
ich habe einen AVM Fritz!Blu USB Stick an einem Raspberry Pi2.
wenn mehr als ein local-bluetooth Gerät definiert wird, kommen keine Ergebnisse mehr zurück.
Wenn ich in der scan routine einen delay von 1 Sekunde einbaue ist alles gut.
in: FHEM/73_PRESENCE.pm
if($mode eq "local-bluetooth")
{
Log3 $name, 5, "PRESENCE ($name) - starting blocking call for mode local-bluetooth";
$hash->{helper}{RUNNING_PID} = BlockingCall("PRESENCE_DoLocalBluetoothScan", $name."|".$hash->{ADDRESS}."|".$local, "PRESENCE_ProcessLocalScan", 60, "PRESENCE_ProcessAbortedScan", $hash);
---->>> sleep(1); <---- damit geht es dann..
}
Gruss
Damit blockierst du aber den Hauptprozess konstant bei jedem Start eines Scans um eine Sekunde in der FHEM komplett still steht.
Für den Fall, dass man mehrere local-bluetooth Definitionen von PRESENCE wird innerhalb des BlockingCall von PRESENCE_DoLocalBluetoothScan() geprüft, ob aktuell ein hcitool Aufruf läuft:
my $wait = 1;
my $ps;
my $psargs = "ax";
if(qx(ps --help 2>&1) =~ /BusyBox/g)
{
Log3 $name, 5, "PRESENCE ($name): found busybox variant of ps command, using \"w\" as parameter";
$psargs = "w";
}
else
{
Log3 $name, 5, "PRESENCE ($name): found standard variant of ps command, using \"ax\" as parameter";
$psargs = "ax";
}
Log3 $name, 4, "PRESENCE ($name): 'which hcitool' returns: $hcitool";
chomp $hcitool;
if(-x $hcitool)
{
while($wait)
{ # check if another hcitool process is running
$ps = qx(ps $psargs | grep hcitool | grep -v grep);
if(not $ps =~ /^\s*$/)
{
# sleep between 1 and 5 seconds and try again
Log3 $name, 5, "PRESENCE ($name) - another hcitool command is running. waiting...";
sleep(rand(4)+1);
}
else
{
$wait = 0;
}
}
Bitte poste mal einen Logauszug mit verbose 5 bei beiden PRESENCE Definitionen.
Gruß
Markus
Mag sein, dass das suboptimal ist - aber wenn die Aufrufe zu schnell hintereinander kommen geht es halt einfach nicht mehr
Der Fix passt für mich, wenn es was schlaueres gibt, her damit.
Und die Logik ob ein anderer prozess läuft ist ok, muss aber was anderes sein....
weil es tritt erst auf wenn mehr als ein device definiert wird.
ohne delay:
2015.02.24 23:40:39 4: PRESENCE (Handy_A): 'which hcitool' returns: /usr/bin/hcitool
2015.02.24 23:40:39 4: PRESENCE (Handy_B): 'which hcitool' returns: /usr/bin/hcitool
2015.02.24 23:40:40 4: PRESENCE (Handy_A) - hcitool returned:
2015.02.24 23:40:40 4: PRESENCE (Handy_B) - hcitool returned:
2015.02.24 23:41:12 4: PRESENCE (Handy_A): 'which hcitool' returns: /usr/bin/hcitool
2015.02.24 23:41:12 4: PRESENCE (Handy_B): 'which hcitool' returns: /usr/bin/hcitool
2015.02.24 23:41:12 4: PRESENCE (Handy_A) - hcitool returned:
2015.02.24 23:41:12 4: PRESENCE (Handy_B) - hcitool returned:
2015.02.24 23:41:43 4: PRESENCE (Handy_B): 'which hcitool' returns: /usr/bin/hcitool
2015.02.24 23:41:43 4: PRESENCE (Handy_A): 'which hcitool' returns: /usr/bin/hcitool
2015.02.24 23:41:43 4: PRESENCE (Handy_B) - hcitool returned:
2015.02.24 23:41:43 4: PRESENCE (Handy_A) - hcitool returned:
mit delay:
2015.02.25 20:36:21 4: PRESENCE (Handy_A): 'which hcitool' returns: /usr/bin/hcitool
2015.02.25 20:36:25 4: PRESENCE (Handy_A) - hcitool returned: Nokia 6233-T
2015.02.25 20:36:27 4: PRESENCE (Handy_B): 'which hcitool' returns: /usr/bin/hcitool
2015.02.25 20:36:27 4: PRESENCE (Handy_B) - hcitool returned: Nokia 6303
2015.02.25 20:39:25 4: PRESENCE (Handy_A): 'which hcitool' returns: /usr/bin/hcitool
2015.02.25 20:39:26 4: PRESENCE (Handy_A) - hcitool returned: Nokia 6233-T
2015.02.25 20:39:28 4: PRESENCE (Handy_B): 'which hcitool' returns: /usr/bin/hcitool
2015.02.25 20:39:32 4: PRESENCE (Handy_B) - hcitool returned: Nokia 6303
2015.02.25 20:42:27 4: PRESENCE (Handy_A): 'which hcitool' returns: /usr/bin/hcitool
2015.02.25 20:42:29 4: PRESENCE (Handy_A) - hcitool returned: Nokia 6233-T
2015.02.25 20:42:32 4: PRESENCE (Handy_B): 'which hcitool' returns: /usr/bin/hcitool
2015.02.25 20:42:33 4: PRESENCE (Handy_B) - hcitool returned: Nokia 6303
Da funktioniert aber die Erkennung bei dir nicht.
Kann es sein, dass FHEM kein "ps" ausführen kann oder dergleichen?
Also Erkennung ist OK, er findet sowohl das hcitool, wie auch die ps funktion wird erkannt,
auch die Warte Logik geht.
ABER wenn ich keinen delay in den Blocking Calls habe, kommt der immer leer zurück.
Habe die Zeit mal auf 0.5 Sekunden reduziert, auch dann geht es.
Wenn ich das delay ganz rausnehme geht es nicht.
Vielleicht ist es ja etwas mit den Blocking Calls und RasPi 2 ?
Müssten dann andere ja auch haben....
Ist ein neu aufgesetztes Raspian auf Raspi 2B+ mit Fritz Blu USB dongle und bluez
Ich schau mal weiter...
2015.02.26 17:05:04 5: PRESENCE (Handy_A) - stopping timer
2015.02.26 17:05:04 5: PRESENCE (Handy_A) - starting blocking call for mode local-bluetooth
2015.02.26 17:05:05 5: PRESENCE (Handy_A): found standard variant of ps command, using "ax" as parameter
2015.02.26 17:05:05 4: PRESENCE (Handy_A): 'which hcitool' returns: /usr/bin/hcitool
2015.02.26 17:05:05 5: PRESENCE (Handy_B) - stopping timer
2015.02.26 17:05:05 5: PRESENCE (Handy_B) - starting blocking call for mode local-bluetooth
2015.02.26 17:05:05 5: PRESENCE (Handy_B): found standard variant of ps command, using "ax" as parameter
2015.02.26 17:05:05 4: PRESENCE (Handy_B): 'which hcitool' returns: /usr/bin/hcitool
2015.02.26 17:05:06 5: PRESENCE (Handy_B) - another hcitool command is running. waiting...
2015.02.26 17:05:08 5: PRESENCE (Handy_B) - another hcitool command is running. waiting...
2015.02.26 17:05:10 4: PRESENCE (Handy_A) - hcitool returned:
2015.02.26 17:05:10 5: Cmd: >{PRESENCE_ProcessLocalScan('Handy_A|0|absent')}<
2015.02.26 17:05:10 5: PRESENCE (Handy_A) - blocking scan result: Handy_A|0|absent
2015.02.26 17:05:10 4: eventTypes: PRESENCE Handy_A abwesend -> abwesend
2015.02.26 17:05:10 4: eventTypes: PRESENCE Handy_A presence: abwesend -> presence: abwesend
2015.02.26 17:05:10 4: eventTypes: PRESENCE Handy_A state: absent -> state: absent
2015.02.26 17:05:10 4: PRESENCE (Handy_A) - rescheduling next check in 180 seconds
2015.02.26 17:05:13 4: PRESENCE (Handy_B) - hcitool returned: Nokia 6303
2015.02.26 17:05:13 5: Cmd: >{PRESENCE_ProcessLocalScan('Handy_B|0|present|Nokia 6303')}<
2015.02.26 17:05:13 5: PRESENCE (Handy_B) - blocking scan result: Handy_B|0|present|Nokia 6303
2015.02.26 17:05:13 4: eventTypes: PRESENCE Handy_B online -> online
2015.02.26 17:05:13 4: eventTypes: PRESENCE Handy_B presence: online -> presence: online
2015.02.26 17:05:13 4: eventTypes: PRESENCE Handy_B device_name: Nokia 6303 -> device_name: Nokia .*
2015.02.26 17:05:13 4: eventTypes: PRESENCE Handy_B state: present -> state: present
2015.02.26 17:05:13 4: PRESENCE (Handy_B) - rescheduling next check in 180 seconds
Ich sehe in der Logausgabe aber keinen Grund dafür. Nutzt du etwa noch anderweitig auf deinem Pi die Bluetoothschnittstelle?
Handy A und B starten fast zeitgleich den Check. Handy A startet das hcitool, Handy B erkennt, das gerade ein Befehl läuft und wartet entsprechend. Handy A sagt abwesend und Handy B nach erfolgtem Check sagt anwesend.
2015.02.26 17:05:04 5: PRESENCE (Handy_A) - stopping timer
2015.02.26 17:05:04 5: PRESENCE (Handy_A) - starting blocking call for mode local-bluetooth
2015.02.26 17:05:05 5: PRESENCE (Handy_A): found standard variant of ps command, using "ax" as parameter
2015.02.26 17:05:05 4: PRESENCE (Handy_A): 'which hcitool' returns: /usr/bin/hcitool
2015.02.26 17:05:05 5: PRESENCE (Handy_B) - stopping timer
2015.02.26 17:05:05 5: PRESENCE (Handy_B) - starting blocking call for mode local-bluetooth
2015.02.26 17:05:05 5: PRESENCE (Handy_B): found standard variant of ps command, using "ax" as parameter
2015.02.26 17:05:05 4: PRESENCE (Handy_B): 'which hcitool' returns: /usr/bin/hcitool
2015.02.26 17:05:06 5: PRESENCE (Handy_B) - another hcitool command is running. waiting...
2015.02.26 17:05:08 5: PRESENCE (Handy_B) - another hcitool command is running. waiting...
2015.02.26 17:05:10 4: PRESENCE (Handy_A) - hcitool returned:
2015.02.26 17:05:10 5: Cmd: >{PRESENCE_ProcessLocalScan('Handy_A|0|absent')}<
2015.02.26 17:05:10 5: PRESENCE (Handy_A) - blocking scan result: Handy_A|0|absent
2015.02.26 17:05:10 4: eventTypes: PRESENCE Handy_A abwesend -> abwesend
2015.02.26 17:05:10 4: eventTypes: PRESENCE Handy_A presence: abwesend -> presence: abwesend
2015.02.26 17:05:10 4: eventTypes: PRESENCE Handy_A state: absent -> state: absent
2015.02.26 17:05:10 4: PRESENCE (Handy_A) - rescheduling next check in 180 seconds
2015.02.26 17:05:13 4: PRESENCE (Handy_B) - hcitool returned: Nokia 6303
Das sieht soweit normal aus. Was jetzt sein kann ist, dass irgend etwas ausserhalb von FHEM auf das Bluetoothinterface zugreift (muss nicht mal hcitool sein).
2015.02.26 17:05:13 5: Cmd: >{PRESENCE_ProcessLocalScan('Handy_B|0|present|Nokia 6303')}<
2015.02.26 17:05:13 5: PRESENCE (Handy_B) - blocking scan result: Handy_B|0|present|Nokia 6303
2015.02.26 17:05:13 4: eventTypes: PRESENCE Handy_B online -> online
2015.02.26 17:05:13 4: eventTypes: PRESENCE Handy_B presence: online -> presence: online
2015.02.26 17:05:13 4: eventTypes: PRESENCE Handy_B device_name: Nokia 6303 -> device_name: Nokia .*
2015.02.26 17:05:13 4: eventTypes: PRESENCE Handy_B state: present -> state: present
2015.02.26 17:05:13 4: PRESENCE (Handy_B) - rescheduling next check in 180 seconds
Hm, denke eher nein.
Das ist ein vor 2 Tagen frisch installierter Raspberry PI 2 mit Raspian default install
und fhem 5.6 + alle updates. Sonst nix am System geändert.
Und mit dem Blue tooth Stick mach ich exklusiv nur die Abfragen für FHEM
mit den beiden Handies. Sonst läuft da nix anderes drauf ausser fhem.
Wie gesagt ich versuche es mal einzukreisen...
Gruss & Danke
Update: Das Problem tritt erst ab dem zweiten BT Device auf, egal ob dieses online oder offline ist
Das hat aber nicht mit den Leerzeichen im Bluetooth Namen zu tun ?
2015.02.26 17:19:20 4: eventTypes: PRESENCE Handy_X device_name: Nokia 6303 -> device_name: Nokia .*
Es sieht so aus, wie wenn das Problem eine Ebene höher wäre.
D.h. wenn nach dem Start der FHEM zwei oder mehrer BT Devices im gleichen poll intervall laufen z.b. 180 sekunden.
Dann hat man ja die Situation, daß zwei Instanzen das Presence Modul aufrufen und das auch immer zur gleichen Zeit tun.
Dafür gibt es auf Basis der PID einen check
Log3 $hash->{NAME}, 4, "PRESENCE ($name) - another check is currently running. skipping check";
ich denke dieser check funktioniert nicht und mein Problem kommt von hier, denn wenn ich die timer auf etwas stelle,
was erstmal keine gemeinsamen Zeiten hat z.b. 25 und 31 Sekunden dann verschwinden die Geräte nach einem
Neustart (weil dann gleichzeitiger poll) und nach 25 bzw 31 sek kommen sie wieder.
ich schau mal weiter....
es sieht aus, wie wenn $hash->{helper}{RUNNING_PID} zu Beginn der Funktion PRESENCE_StartLocalScan immer
leer sei, also die PIDs, welche zurückkommen, nicht funktionsübergreifend gespeichert würden
Noch ein anderer Gedanke:
wenn zwei devices das gleiche Poll Intervall haben (Handy_A und Handy_B) z.B. 30 Sekunden
Dann passiert doch folgendes:
1) Neustart FHEM
2) Devices werden initialisiert und starten damit gleich einen ersten poll (nahezu gleichzeitig)
3) Das Device, welches minimal später kommt wird in der Funktion PRESENCE_StartLocalScan durch
unless(exists($hash->{helper}{RUNNING_PID})) in die Warteschleife geschickt, welche wieder
das gleiche Intervall hat 30 Sekunden
4) nach weiteren 30 Sekunden pollen wieder BEIDE zur fast gleichen Zeit und es passiert geht bei 3) weiter
Klingt für mich, wie eine nicht auflösbare Situation, weil bei gleichem Raster kommen die Polls gleich und einer
der beiden geht in die Warteschleife, und wenn es blöd läuft ist das immer der gleiche...
oder mach ich einen Denkfehler ?
Ja, du machst einen Denkfehler ;-) Es passiert so:
1. Neustart FHEM
2. Devices werden initialisiert und starten damit gleich einen ersten poll (nahezu gleichzeitig)
3. Das erste Device startet seinen Scan sofort, da kein hcitool-Prozess auf dem Rechner läuft
4. Das zweite Device prüft zuerst ob ein hcitool-Aufruf läuft. Es stellt fest, das bereits einer läuft, wartet 2 Sekunden und prüft dann erneut usw.
5. Der hcitool-Aufruf des ersten Device ist beendet und das Ergebnis wird an FHEM zurück geliefert
6. Das zweite Device sieht, es läuft kein hcitool-Aufruf mehr, also startet es seinen hcitool Aufruf. Normalerweise müsste dieser nun ein Ergebnis zurückgeben, das tut er in diesem Fall aber nicht.
Normalerweise funktioniert das so ohne Probleme, was sein kann ist, da die FritzBox ja etwas langsamer ist, als andere Boards, evtl. den Timer zum warten bei einem laufenden hcitool-Prozess hoch zu setzen:
Zeile 788:
Zitatsleep(rand(4)+5);
Da das zweite Device in diesem Fall länger brauch, wird auch der Timer entsprechend später gesetzt. Erst wenn der Scan fertig ist, wird der Timer wieder neu angestoßen, damit es eben nicht passiert, dass immer wieder die selben Devices zeitgleich aufeinander treffen.
Die genannte Zeile unless(exists($hash->{helper}{RUNNING_PID})) dient dazu, das für ein Device auch nur max. 1 Check zur selben Zeit läuft und nicht mehrere Checks zeitgleich für ein und dasselbe Device gestartet werden (wegen Überlast).
Gruß
Markus
Hallo Markus,
danke für die gute Erklärung !
Ich habs probiert, mit dem sleep(rand(4)+5); - es ist leider immer noch so, daß er dann gar keine BT Devices mehr findet.
Nur mit meinem "Ekelpatch" also sleep(1) innerhalb von PRESENCE_StartLocalScan nach dem PRESENCE_DoLocalBluetoothScan
funktioniert es.
Ich such mir einen Wolf und finde keine Ursache.
Das Einzige was mich wundert ist, daß das Problem anscheinend kein anderer hat ? weil
AVM BT Stick an Raspberry PI sollte jetzt ja nicht SO ungewöhnlich sein...
Ich werde weitersuchen :-)
Gruss & Danke
Hi,
hast du den Fehler finden können? Bei mir tritt der Fehler ebenfalls auf:
2015.10.30 20:20:17 1: Timeout for PRESENCE_DoLocalBluetoothScan reached, terminated process 23829
2015.10.30 20:20:17 2: PRESENCE (Dominik_Nexus7_BT) - device could not be checked (retrying in 10 seconds)
2015.10.30 20:20:43 2: PRESENCE (Dominik_Nexus7_BT) - check returned a valid result after 1 unsuccesful retry
2015.10.30 20:48:24 1: Timeout for PRESENCE_DoLocalBluetoothScan reached, terminated process 1004
2015.10.30 20:48:24 2: PRESENCE (Dominik_iPhone_BT) - device could not be checked (retrying in 10 seconds)
2015.10.30 20:48:44 2: PRESENCE (Dominik_iPhone_BT) - check returned a valid result after 1 unsuccesful retry
In Summe habe ich 3 BT PRESENCE Devices angelegt. Alle werden alle 5s bei Abwesenheit geprüft. Zu den obigen Zeitpunkt waren alle Geräte abwesend. Wenn ich anwensend bin, prüfe ich nur alle 60s, da tritt der Fehler nicht auf. Ich vermute fast, dass die 5s ein zu kurzes Intervall sind und sich dann so viele Anfragen in der Queue befinden, dass es nicht mehr korrekt abgearbeitet werden kann. Weil im Worst Cast ist das sleep(rand(4)+1) eben 5s und das ist vielleicht in meinem Fall zu lang!?
Ich probier mal die Zeit auf 6s und 7s für die Devices zu stellen. Mal sehen ob das was ändert.
Wenn ihr Ideen habt, gerne her damit :)
Zitat von: dominik am 31 Oktober 2015, 09:44:44
Ich probier mal die Zeit auf 6s und 7s für die Devices zu stellen. Mal sehen ob das was ändert.
Wenn ihr Ideen habt, gerne her damit :)
Benutze zwar nur den lan-ping, kann dir aber den Rat geben die Prüfungen zeitlich zu trennen. Habe schon allein wegen Lastverteilung unterschiedliche Zeiten angesetzt. So habe ich auch mit 45 zu prüfenden IP Adressen wenig bis keine Probleme.
Ich habe leider das gleiche Problem insgesammt 6 Presence BT Definitionen, 10sek bei Ab-. und 45 sek bei Anwesenheit, und Timeouts nur wenn alle geräte abwesend sind. Seit ihr damals zu einer brauchbaren Lösung gekommen?
Ich habe die Zeiten etwas variiert, damit klappt es nun ganz gut. Habe nun 14s und 11s bei Abwesenheit eingestellt. 60s bei Anwesenheit. Damit kommt kein Fehler mehr.
Habe das Gefühl, dass Zeiten unter 10s auch manchmal Probleme machen.