MQTT2_Client mit SSL u. Zertifikat

[KölnSolar]

ich versuche ein neues device in FHEM einzubinden, welches mqtt spricht. Der mqtt-server ist extern(evtl. später über MQTT2_Server zu realisieren). Mit MQTT.fx habe ich es geschafft topics beim Server zu subscriben. Dazu musste ich SSL aktivieren und den Pfad zu einem CA-Zertifikat angeben.

mein device sieht so aus

Code Auswählen Erweitern

defmod myecovacsclient MQTT2_CLIENT 192.168.178.47:8883
attr myecovacsclient SSL 1
attr myecovacsclient autocreate simple
attr myecovacsclient clientId helper1\@bumper\/helper1
attr myecovacsclient keepaliveTimeout 60
attr myecovacsclient subscriptions #
attr myecovacsclient username tmpuser@ecouser.net/GLB19396e86
attr myecovacsclient verbose 5

setstate myecovacsclient disconnected
setstate myecovacsclient 2019-09-14 21:03:10 state disconnected

Der state wechselt permanent zw. opened/disconnected(connecting=3). Ich denke, das liegt an dem nicht auffindbaren Zertifikat. Wie mach ich das aber bekannt ?

Grüße Markus
PS: Das disable-Attribut hat keine Wirkung 

Edit: Vielleicht hilft der Python-Code, den ich ersetzen will, bei der Antwortfindung. 

Code Auswählen Erweitern

class MQTTHelperBot:

    Client = None
    wait_resp_timeout_seconds = 10
    expire_msg_seconds = 10

    def __init__(self, address):
        self.address = address
        self.client_id = "helper1@bumper/helper1"
        self.command_responses = []

    async def start_helper_bot(self):

        try:
            if self.Client is None:
                self.Client = MQTTClient(
                    client_id=self.client_id, config={"check_hostname": False}
                )

            await self.Client.connect(
                "mqtts://{}:{}/".format(self.address[0], self.address[1]),
                cafile=bumper.ca_cert,
            )
            await self.Client.subscribe(
                [
                    ("iot/p2p/+/+/+/+/helper1/bumper/helper1/+/+/+", QOS_0),
                    ("iot/p2p/+", QOS_0),
                    ("iot/atr/+", QOS_0),
                ]
            )

            asyncio.create_task(self.get_msg())

Der Server wurde so definiert

Code Auswählen Erweitern

class MQTTServer:
    default_config = {}
    broker = None

    async def broker_coro(self):

        mqttserverlog.info(
            "Starting MQTT Server at {}:{}".format(self.address[0], self.address[1])
        )
        self.broker = hbmqtt.broker.Broker(config=self.default_config)

        try:
            await self.broker.start()
mit

Code Auswählen Erweitern

            self.default_config = {
                "listeners": {
                    "default": {"type": "tcp"},
                    "tls1": {
                        "bind": "{}:{}".format(address[0], address[1]),
                        "ssl": "on",
                        "certfile": bumper.server_cert,
                        "keyfile": bumper.server_key,
                    },
                },
                "sys_interval": 10,
                "auth": {
                    "allow-anonymous": False,
                    "password-file": os.path.join(
                        os.path.dirname(os.path.realpath(__file__)), "passwd"
                    ),
                    "plugins": ["bumper"],  # No plugins == no auth
                },
                "topic-check": {"enabled": False},
            }
Mit MQTT2_Server ersetzbar ?

[rudolfkoenig]

Soweit ich es beurteilen kann, kann man mit MQTT2_CLIENT z.Zt. fuer eine SSL-Verbindung kein Client-Zertifikat mitgeben.
Liegt wohl daran, dass MQTT2_CLIENT HttpUtils ueber DevIO anspricht, und DevIO gibt keine Parameter weiter.
Ist SSL mit Benutzer/Passwort keine Loesung?

[KölnSolar]

Leider nein.  Das device kommuniziert über 4 verschiedene Server u. einem Hilfs-mqtt-client mit diversen Authorisierungen. Das hat dann jemand in Python nachgebaut.
Ich hab jetzt mal versucht den mqtt-Server ohne SSL zu starten, aber dann meldet sich das device nicht mehr über den Server beim Hilfs-client  . Aber ich denke, dass das der Weg ist, um dann evtl. auch den Server mit FHEM ablösen zu können...

[KölnSolar]

Hi Rudi,
mühsam nährt sich das Eichhörnchen. Mir ist jetzt aufgefallen, dass im Python-Skript eine "Berechtigungsprüfung" erfolgt, die auf die clientId abhebt. Die muss zwingend user@string1/string2 sein. Im MQTT2_CLIENT werden aber die Sonderzeichen im Attribut clientId automatisch "eliminiert". Gibt es dazu einen Grund ? Ich hab das mal lokal bei mir rausgenommen.
Außerdem wird bei einem defmod das Attribut clientId ignoriert. Erst ein erneutes set aktiviert das Attribut. Ich denke das ist ein bug.
Grüße Markus
PS: Ich hab mich gestern etwas intensiver mit Python-HBMQTT auseinandergesetzt. Ist ganz hilfreich beim debugging.

[rudolfkoenig]

Habe MQTT2_CLIENT angepasst:
- das clientId Attribut wird bei modify beruecksichtigt
- clientId wird nicht mehr beschnitten. Grund war (wenn ich mich recht erinnere) autocreate, ich habe jetzt die clientId Bereinigung dahin verschoben. ACHTUNG: das kann (leider) fuer aktuelle Konfigurationen zu Problemen fuehren, wenn clientId (oder MQTT2_CLIENT Name) Unterstriche enthielt und im MQTT2_DEVICE readingsList diese (gekuerzte) clientId beruecksichtigt. Ich bin aber der Ansicht, dass diese Aenderung Vorrang hat, und die problematische Konfiguration angepasst werden sollte.
- ich habe ein sslargs Attribut eingefuegt, was zu einem Hash konvertiert wird, was wiederum bis HttpUtils durchgeschleift wird: damit sollte man ein Client-Zertifikat spezifizieren koennen. Habs nicht getestet, und verweise auf "perldoc IO::Socket::SSL". Freue mich aber ueber (positiven) Feedback

[KölnSolar]

wird sofort aus dem SVN heruntergeladen und getestet.
Danke Dir

[KölnSolar]

leider kein positives Feedback. 
mit global verbose 5 sehe ich nur

Code Auswählen Erweitern

2019.09.16 22:15:55 3: Opening myecovacsclient device 192.168.178.47:8883
2019.09.16 22:15:55 5: HttpUtils url=https://192.168.178.47:8883/
2019.09.16 22:15:55 4: IP: 192.168.178.47 -> 192.168.178.47
2019.09.16 22:15:56 5: myecovacsclient: sending CONNECT (16)@(0)(6)MQIsdp(3)(194)(0)(30)(0)(28)fhemuser2@bumper/GLB19396e86(0)(12)test@egal.de(0)(6)123456
2019.09.16 22:15:56 5: SW: 104000064d514973647003c2001e001c6668656d75736572324062756d7065722f474c423139333936653836000c74657374406567616c2e64650006313233343536
2019.09.16 22:15:56 3: myecovacsclient device opened
2019.09.16 22:15:56 5: Starting notify loop for myecovacsclient, 1 event(s), first is CONNECTED
2019.09.16 22:15:56 5: End notify loop for myecovacsclient

wäre schön, wenn es so wäre, aber dann kommt

Code Auswählen Erweitern

2019.09.16 22:15:56 1: 192.168.178.47:8883 disconnected, waiting to reappear (myecovacsclient)
2019.09.16 22:15:56 5: Starting notify loop for myecovacsclient, 1 event(s), first is DISCONNECTED
2019.09.16 22:15:56 5: End notify loop for myecovacsclient
2019.09.16 22:15:56 5: HttpUtils url=https://192.168.178.47:8883/
2019.09.16 22:15:56 4: IP: 192.168.178.47 -> 192.168.178.47
2019.09.16 22:15:56 5: myecovacsclient: sending SUBSCRIBE (130)(6)(0)(24)(0)(1)#(0)
2019.09.16 22:15:56 1: 192.168.178.47:8883 reappeared (myecovacsclient)
2019.09.16 22:15:56 5: Starting notify loop for myecovacsclient, 1 event(s), first is CONNECTED
2019.09.16 22:15:56 5: End notify loop for myecovacsclient

Und reappeared (und state opened) ist geflunkert, subscribe hätte gar nicht ausgeführt werden dürfen. 

Leider sehe ich nicht, was wirklich gesendet und geantwortet wird. Kann ich durch eine kleine Modifikation an der richtigen Stelle mehr Info bewirken ?

Der state ist kurz auch disconnected

[rudolfkoenig]

Leider sehe ich nicht, was wirklich gesendet und geantwortet wird.

Was gesendet wird, steht zweimal da:

einmal im "Klartext", Befehl dekodiert und nicht druckbare Zeichen als Dezimalzahl in Klammern dargestellt:

myecovacsclient: sending CONNECT (16)@(0)(6)MQIsdp(3)(194)(0)(30)(0)(28)fhemuser2@bumper/GLB19396e86(0)(12)test@egal.de(0)(6)123456

und einmal als Hex (SW: kommt von DevIO_SimpleWrite)

SW: 104000064d514973647003c2001e001c6668656d75736572324062756d7065722f474c423139333936653836000c74657374406567616c2e64650006313233343536

Dekodiern kannst du es mit

Code Auswählen Erweitern

perl -e 'print pack("H*","104000064d514973647003c2001e001c6668656d75736572324062756d7065722f474c423139333936653836000c74657374406567616c2e64650006313233343536")' | xxd


Um den Empfang zu debuggen musst Du fuer die MQTT2_CLIENT Instanz verbose auf 5 setzen (global reicht nicht).

[KölnSolar]

Schon klar. Ich meinte auf der Protokollebene. 
Ich versteh einfach nicht das disconnected und späteres reappeared. Ich spekuliere, dass der Socketaufbau erfolgt, die SSL-Prüfung aber in die Hose geht und dann ohne SSL der socket auf opened bleibt. 

httputils u. devio sind dann doch etwas zu hoch für meine Perl-Kenntnisse 

[rudolfkoenig]

Fuers Protokoll empfehle ich (wie in der .pm Datei hinterlegt ist): http://docs.oasis-open.org/mqtt/mqtt/v3.1.1/os/mqtt-v3.1.1-os.html

Ansonsten: erst wenn die TCP Verbindung steht (mit TLS/SSL, wenn so bestellt), sendet das Modul eine CONNECT Nachricht.Und die Gegenseite hat auch CONNACK mit rc==0 geschickt, erst danach sendet das Modul die SUBCRIBE Nachricht.Es waere interessant zu sehen, ob danach ein SUBACK erfolgt, oder nur die Verbindung geschlossen wird.

[KölnSolar]

Vor dem SUBSCRIBE ist der disconnect schon da. Ich hab mal ein paar Logmeldungen eingebaut, um zu sehen, wie der Programmablauf ist. Kannst Du damit etwas anfangen ?

Code Auswählen Erweitern

2019.09.17 15:58:45 3: Opening myecovacsclient device 192.168.178.47:8883
2019.09.17 15:58:45 5: HttpUtils url=https://192.168.178.47:8883/
2019.09.17 15:58:45 4: IP: 192.168.178.47 -> 192.168.178.47
2019.09.17 15:58:45 4: HttpUtils mein Logging vor call Connect2
2019.09.17 15:58:45 4: HttpUtils Connect2 SSL nach start_SSL
2019.09.17 15:58:45 4: HttpUtils Connect2 SSL noConn2 callback
2019.09.17 15:58:45 5: myecovacsclient: sending CONNECT (16)@(0)(6)MQIsdp(3)(194)(0)(30)(0)(28)fhemuser2@bumper/GLB19396e86(0)(12)test@egal.de(0)(6)123456
2019.09.17 15:58:45 5: SW: 104000064d514973647003c2001e001c6668656d75736572324062756d7065722f474c423139333936653836000c74657374406567616c2e64650006313233343536
2019.09.17 15:58:45 3: myecovacsclient device opened
2019.09.17 15:58:45 4: HttpUtils mein Logging nach call Connect2
2019.09.17 15:58:45 1: 192.168.178.47:8883 disconnected, waiting to reappear (myecovacsclient)
2019.09.17 15:58:45 5: HttpUtils url=https://192.168.178.47:8883/
2019.09.17 15:58:45 4: IP: 192.168.178.47 -> 192.168.178.47
2019.09.17 15:58:45 4: HttpUtils mein Logging vor call Connect2
2019.09.17 15:58:46 4: HttpUtils Connect2 SSL nach start_SSL
2019.09.17 15:58:46 4: HttpUtils Connect2 SSL noConn2 callback
2019.09.17 15:58:46 5: myecovacsclient: sending SUBSCRIBE (130)(6)(0)B(0)(1)#(0)
2019.09.17 15:58:46 1: 192.168.178.47:8883 reappeared (myecovacsclient)
2019.09.17 15:58:46 4: HttpUtils mein Logging nach call Connect2
Es erfolgt also der SSL-connect, aber dann(warum, also was ist der Auslöser) geht das device wieder auf disconnected. Wenn es dann wieder kommt, wird doinit bzw. send CONNECT nicht mehr ausgeführt, weil $hash->{connecting} nun 2 oder 3 ist.

[rudolfkoenig]

Kannst Du damit etwas anfangen ?

Nicht wirklich, da ich nicht weiss, wo genau die Logs eingebaut sind.
Ich haette lieber ein "attr myecovacsclient verbose 5" Log.

[KölnSolar]

das ist ein verbose5-Log.  wenn Du nicht die zusätzlichen Loggings "httputils...." betrachtest.
Die zusätzlichen Loggings in httputils sind in der sub ...connect vor und nach dem call der sub ...connect2. Dann in ...connect2 nach dem Aufruf von .....start_SSL und schließlich noch vor Aufruf der callback-Funktion, wenn ($hash->{noConn2}) wahr ist.

Edit: Ich hab jetzt mal den Python-MQTT-Server(und natürlich den myecovacsclient) ohne SSL gestartet. Das selbe Problem. Das Log sieht bis auf mein Logging "startSSL"(fehlt jetzt richtigerweise) identisch aus. MQTT.fx hat keine Probleme.
Es muss also etwas anderes sein, was der Server scheinbar nicht mag.

btw. das Internal SSL bekommt man durch Attribut-Löschung nicht entfernt.

[rudolfkoenig]

Ich habe MQTT2_CLIENT.pm angepasst, damit in solchen Faellen kein sinnloses SUBSCRIBE geschickt wird.

Aendert aber vmtl. nichts an dem eigentlichen Problem.
Und um die Loesung zusaetzlich zu erschweren, schliesst der MQTT Server die Verbindung, anstatt (wie im Protokoll spezifiziert) per CONNACK zu sagen, was nicht passt.

[KölnSolar]

Nein, hilft nicht wirklich. Außer, dass ich jetzt ein Flashlight im detailsview habe: disconnected/opened. Das pendant im Log: disconnected/reappeared

Jetzt wär das disable-Attribut nicht schlecht. 

Ich wurstle mich mal weiter durch das Python-Skript. Kann doch nicht angehen, dass MQTT.fx  funktioniert und wir das nicht ans laufen kriegen.   Hab extra clientId, user u. Passwort per cut&paste aus MQTT.fx übertragen. Ändert nix.