[Erkenntnis] MQTT_DEVICE mit verbose 5

Gisbert · 26 Mai 2020, 11:45:37

Hallo zusammen,

ich nutze mehrere (viele) MQTT_DEVICE(s) und wollte bei einem Device detailiertere Logdaten, also habe ich verbose 5 eingestellt.

Im Fhemlog bekomme ich jetzt aber von allen Geräten viele Einträge in der Logdatei.

Wie kann das sein?

Viele Grüße Gisbert

rudolfkoenig · 26 Mai 2020, 12:09:17

Vertippt (z.Bsp. als attr global verbose 5)?
Oder alle Geraete haben ein "attr verbose 5"?
Wenn nicht, dann bitte mit Config+Log Beispielen Nachweise bringen.

Gisbert · 26 Mai 2020, 16:06:06

Hallo Rudi,

ich hab den "Versuch" wiederholt.
Im folgenden Device habe ich das Attribut verbose ausgewählt und per Dropdown-Menü auf 5 eingestellt, sowie ein save config durchgeführt.

Code Auswählen

gelöscht, da Sachverhalt geklärt

Im Logfile erhalte ich folgendes, eine Menge:

Code Auswählen

gelöscht, da Sachverhalt geklärt

Während der ganzen Aktion stand das Attribut verbose des Devices global unverändert auf 3.

Schon merkwürdig, oder nicht?

Viele Grüße Gisbert

Beta-User · 26 Mai 2020, 16:25:11

Weiß nicht, ob das merkwürdig ist:
https://svn.fhem.de/trac/browser/trunk/fhem/FHEM/00_MQTT.pm#L544 (bzw. L546) ruft wohl alle Clients eines IO's auf, und loggt dann "in deren Namen", was dann wohl von fhem.pl entsprechend so verstanden wird, dass eben der verbose-Level des namentlich genannten Devices anzuwenden sein soll. Allerdings ist der Code im IO, und der Mechanismus erscheint daher etwas seltsam...

MMn. kannst du einfach Zeile 546 deaktivieren, wenn du das weg haben willst, oder in den Bereich nach dem darauffolgenden if verschieben, um nur "passende" Messages zu sehen (was aber wohl für das Debugging des Entwicklers nicht passend wäre).

rudolfkoenig · 26 Mai 2020, 16:51:23

Das MQTT-Modul geht beim Empfang einer MQTT-Nachricht alle MQTT_DEVICE Instanzen durch, loggt jede Nachricht in dem Namen von jedem Device (die erwaehnte Zeile 546), und entscheidet erst dann, ob die MQTT Nachricht fuer diese Instanz ueberhaupt relevant ist.

Anders formuliert: bei 100 MQTT_DEVICE Instanzen wird die Log Funktion fuer jede einzelne MQTT-Nachricht 100-mal aufgerufen.

Gisbert · 26 Mai 2020, 17:02:43

Zitat von: rudolfkoenig am 26 Mai 2020, 16:51:23
Das MQTT-Modul geht beim Empfang einer MQTT-Nachricht alle MQTT_DEVICE Instanzen durch, loggt jede Nachricht in dem Namen von jedem Device (die erwaehnte Zeile 546), und entscheidet erst dann, ob die MQTT Nachricht fuer diese Instanz ueberhaupt relevant ist.

Anders formuliert: bei 100 MQTT_DEVICE Instanzen wird die Log Funktion fuer jede einzelne MQTT-Nachricht 100-mal aufgerufen.

Hallo Rudi und Beta-User,

Damit wird verständlich, warum es zu diesem Verhalten kommt.
Die Frage ist jedoch, ob genau das beabsichtigt war, so wie es jetzt programmiert wurde.
Nach meinem Verständnis würde ich erwarten, dass nur die Meldungen zum jeweiligen Device geloogt werden?

Kann man das umstellen, offiziell, und wie seht ihr das?

Viele Grüße Gisbert

Beta-User · 26 Mai 2020, 17:21:17

MMn ist das "works as designed" - ob das hexenmeister je so programmiert hätte, ist eine andere Frage, und das ganze stammt aus einer Zeit, in der MQTT noch nicht so verbreitet war...
U.A. an der Stelle sind m.E. die MQTT2-Module deutlich ressourcensparender konzipiert.

Ich muß mir aber mal ansehen, ob ich da auch in MYSENSORS/MYSENSORS_DEVICE so eine Altlast drin habe; für mich macht die Zeile nur zum debuggen Sinn; (btw: außerdem sind auch z.B. in WeekdayTimer einige Log3-Aufrufe drin, die evtl. nicht mehr gebraucht werden (aber sehr viel seltener aufgerufen, da weniger Anlässe)).

Ggf. wäre es sinnvoll, auch die MQTT-Module dahingehend mal zu durchforsten, ich nehme aber mal an, dass das schwierig wird, da hexenmeister neulich in anderen Zusammenhängen signalisiert hatte, derzeit wenig Zeit zu haben. (=> selber durchforsten und ggf. patches vorschlagen; muß ja nicht gleich ganz rausfliegen, deaktivieren würde für's erste reichen...).

rudolfkoenig · 26 Mai 2020, 17:57:00

Off-Topic:

ZitatIch muß mir aber mal ansehen, ob ich da auch in MYSENSORS/MYSENSORS_DEVICE so eine Altlast drin habe

Bei MYSENSORS wird das gleiche Mechanismus verwendet wie beim MQTT: die Benachrichtigung geht ueber GP_ForallClients. Weiterhin ist bei beiden eine starke Verzahnung der logischen mit dem physischen Modul zu sehen, was das Wiederverwenden der Module im anderen Kontext (z.Bsp. MQTT_DEVICE als Client von MQTT2_SERVER) unmoeglich macht.

Der empfohlene Weg ist Dispatch/ParseFn um Nachrichten zu verteilen, bzw. IOWrite/WriteFn um Nachrichten zu senden.

Beta-User · 26 Mai 2020, 18:12:05

Hmm, zu OT:

bei MySensors bin ich mir nicht so sicher, ob die Verzahnung nicht sogar sinnvoll ist, aber ggf. könnten wir an anderer Stelle mal vertiefen, wie das mit dem dispatch konkret aussehen müßte (das könnte ggf. helfen bei dem Weg Richtung Subdevices für einzelne Kanäle?).
Bei MySensors ist das "Problem", dass man nur einen Zahlenraum von 0-254 für die Nodes hat und uU. doppelte Belegungen vorhanden sind, die man per IO auseinanderhalten muß. Jedenfalls das hat bisher reibungslos funktioniert... (Zumindest habe ich vor einiger Zeit die "0"-Clients = das, was auf dem GW an Sensorik ist, in separate Devices pro IO aufgliedern können).

Um Nachrichten zu senden wird der Hash des IO's verwendet, andere wären auch nicht sinnvoll (bzw. nur in einem einzigen speziellen Fall, in dem das dann sogar erzwungen wird).

rudolfkoenig · 26 Mai 2020, 18:38:37

Ich sage nicht, dass es nicht funktioniert, aber diese Verzahnung macht das Ersetzen der Komponenten unmoeglich. Am Anfang kann man nicht vorstellen, dass es sinvoll sein kann, wir haben aber viele Beispiele, wo es nuetzlich ist: MQTT2_CLIENT vs MQTT2_SERVER, CUL vs. FHZ, usw. Die Notwendigkeit kam jeweils erst spaeter. Ob man MYSENSORS umbauen sollte, ist fraglich, aber bei neuen Modulen sollte man den Weg nicht verbauen.

Wenn man fuer jedes Client ein eindeutiges ID hat, dann ist das Suchen per Schleife (siehe matchClient/GP_ForallClients) nicht so effizient, wie ein Hash-Lookup. In meinen Modulen wird dieser Hash im Client-Modul als lokale Variable gepflegt, jeweils in DefFn und UndefFn
Bei MQTT mit beliebigen subscriptions je Client ist das nicht mehr so einfach.

hexenmeister · 27 Mai 2020, 23:39:47

Das Logging hier ist wirklich unglücklich programmiert. Ich werde die Zeile einfach hinter das if verschieben. Es sollten auch keine u.U. Meldungen flöten gehen, denn wenn für sie kein Client zuständig ist, sollten sie hier gar nicht ankommen (wäre ggf. ein Fehler).

Die Module für MQTT und MySensors stammen beide ehemals vom selben Autor und weisen starke Ähnlichkeiten auf. Beta-User und ich haben sie schon so geerbt.