Autor Thema: [Bugs] 00_MQTT2_SERVER / 10_MQTT2_DEVICE  (Gelesen 8807 mal)

Offline Prof. Dr. Peter Henning

  • Developer
  • Hero Member
  • ****
  • Beiträge: 6080
Antw:[Bugs] 00_MQTT2_SERVER / 10_MQTT2_DEVICE
« Antwort #150 am: 07 Oktober 2018, 08:59:34 »
1.Problem in MQTT2_DEVICE:

Eine Kommandodefinition
attr <device> setList relay_0 shellies/shelly4pro-061D51/relay/0/commanderzeugt korrekterweise im FHEMWEB eine Drop-Down-Liste mit "relay_0" als Kommando und einem Textfeld für einen Parameter dahinter. Bei Eingabe von z.B. "on" oder "off" im Textfeld wird das betreffende Device richtig geschaltet.

Wenn man nun setzt
attr <device> setList relay_0:on,off shellies/shelly4pro-061D51/relay/0/commanderzeugt dies im FHEMWEB eine Drop-Down-Liste mit "relay_0" als Kommando und einer weiteren Drop-Down-Liste mit der Auswahl zwischen "on" und "off". Bei der Ausführung allerdings steigt die "Set"-Routine in Zeile 218 des Moduls aus mit der Fehlermeldung
Zitat
Unknown argument relay_0, choose one of relay_0:on,off ...
.

Edit: Problem gelöst, danke.

LG

pah
« Letzte Änderung: 08 Oktober 2018, 12:55:24 von Prof. Dr. Peter Henning »

Offline Prof. Dr. Peter Henning

  • Developer
  • Hero Member
  • ****
  • Beiträge: 6080
Antw:[Bugs] 00_MQTT2_SERVER / 10_MQTT2_DEVICE
« Antwort #151 am: 07 Oktober 2018, 09:10:31 »
2. Problem im Zusammenspiel zwischen MQTT2_DEVICE und MQTT2_SERVER:

Das per autocreate erzeugte Device" shelly4pro_061D51" habe ich (natürlich aus Schreibfaulheit) umbenannt in "shellypro", die Definition im cfg-File lautet also
    
define shellypro MQTT2_DEVICE shelly4pro_061D51
Jetzt gibt es im Log aber von Zeit zu Zeit so etwas hier
Zitat
2018.10.07 08:45:45 3: mqtt: mqtt_192.168.0.170_57333 left us (keepalive check)
2018.10.07 08:51:42 1: M2: Unhandled packet PUBACK, disconneting mqtt_192.168.0.170_55990
2018.10.07 08:51:42 2: autocreate: define MQTT2_shelly4pro_061D51 MQTT2_DEVICE shelly4pro_061D51
2018.10.07 08:51:42 2: autocreate: define FileLog_MQTT2_shelly4pro_061D51 FileLog ./log/MQTT2_shelly4pro_061D51-%Y.log MQTT2_shelly4pro_061D51
2018.10.07 08:51:46 1: M2: Unhandled packet PUBACK, disconneting mqtt_192.168.0.170_55381

Klar kann man das Neuanlegen durch autocreate=0 unterdrücken. Allerdings will man ja von Zeit wirklich ein neues Device anbinden - und dann werden alle anderen Devices, die gerade mal nicht erreichbar sind, neu angelegt.

LG

pah

Offline rudolfkoenig

  • Administrator
  • Hero Member
  • *****
  • Beiträge: 19485
Antw:[Bugs] 00_MQTT2_SERVER / 10_MQTT2_DEVICE
« Antwort #152 am: 07 Oktober 2018, 12:33:59 »
attr <device> setList relay_0:on,off shellies/shelly4pro-061D51/relay/0/commandAn diese Variante habe ich nicht gedacht, hab sie jetzt aber implementiert und eingecheckt.
Workaround: widgetOverride verwenden.

Weiterhin gefixt: WARNING falls man MQTT2_SERVER mit allowed verwendet.

Offline rudolfkoenig

  • Administrator
  • Hero Member
  • *****
  • Beiträge: 19485
Antw:[Bugs] 00_MQTT2_SERVER / 10_MQTT2_DEVICE
« Antwort #153 am: 07 Oktober 2018, 12:46:48 »
2018.10.07 08:51:42 1: M2: Unhandled packet PUBACK, disconneting mqtt_192.168.0.170_55990
2018.10.07 08:51:42 2: autocreate: define MQTT2_shelly4pro_061D51 MQTT2_DEVICE shelly4pro_061D51
Ich habe PUBACK jetzt ignoriert, es wird kein disconnect erzwungen.

Das sollte aber kein Grund fuer autocreate sein. Um das zu verstehen brauche ich ein "attr mqtt verbose 5" Log, direkt vor dem autocreate, noch besser mit auskommentierten "Lowlevel debugging" in 00_MQTT2_SERVER.pm. Die Umbenennung sollte nicht die Ursache sein, insb. wenn man clientId nicht entfernt hat.

Offline Prof. Dr. Peter Henning

  • Developer
  • Hero Member
  • ****
  • Beiträge: 6080
Antw:[Bugs] 00_MQTT2_SERVER / 10_MQTT2_DEVICE
« Antwort #154 am: 07 Oktober 2018, 13:18:21 »
Ich schau mal, ob ich das kurzfristig liefern kann. Ansonsten Danke für den Fix.

Edit: Hier ein Schaltvorgang mit verbose 5 beim Device und beim Server. autocreate ist 0. Ich habe nichts gesehen, aus dem ich schlau würde.
2018.10.07 13:23:06 5: mqtt_192.168.0.170_55697 shelly4pro-061D51 => shellies/shelly4pro-061D51/relay/0/command:on
2018.10.07 13:23:06 1: M2: Unhandled packet PUBACK, disconneting mqtt_192.168.0.170_55697
2018.10.07 13:23:06 4: mqtt_192.168.0.170_55697 shelly4pro-061D51 PUBLISH shellies/shelly4pro-061D51/relay/0:on
2018.10.07 13:23:06 5: mqtt: dispatch shelly4pro_061D51:shellies/shelly4pro-061D51/relay/0:on
2018.10.07 13:23:08 4: Connection accepted from mqtt_192.168.0.170_61038
2018.10.07 13:23:08 4: mqtt_192.168.0.170_61038 shelly4pro-061D51 CONNECT V:4 keepAlive:60
2018.10.07 13:23:08 4: mqtt_192.168.0.170_61038 shelly4pro-061D51 PUBLISH shellies/shelly4pro-061D51/relay/0/power:29.52
2018.10.07 13:23:08 5: mqtt: dispatch shelly4pro_061D51:shellies/shelly4pro-061D51/relay/0/power:29.52
2018.10.07 13:23:08 4: mqtt_192.168.0.170_61038 shelly4pro-061D51 PUBLISH shellies/shelly4pro-061D51/relay/0/energy:1
2018.10.07 13:23:08 5: mqtt: dispatch shelly4pro_061D51:shellies/shelly4pro-061D51/relay/0/energy:1
2018.10.07 13:23:08 4: mqtt_192.168.0.170_61038 shelly4pro-061D51 PUBLISH shellies/shelly4pro-061D51/relay/0:on
2018.10.07 13:23:08 5: mqtt: dispatch shelly4pro_061D51:shellies/shelly4pro-061D51/relay/0:on
2018.10.07 13:23:08 4: mqtt_192.168.0.170_61038 shelly4pro-061D51 PUBLISH shellies/shelly4pro-061D51/relay/1:off
2018.10.07 13:23:08 5: mqtt: dispatch shelly4pro_061D51:shellies/shelly4pro-061D51/relay/1:off
2018.10.07 13:23:08 4: mqtt_192.168.0.170_61038 shelly4pro-061D51 PUBLISH shellies/shelly4pro-061D51/relay/2:off
2018.10.07 13:23:08 5: mqtt: dispatch shelly4pro_061D51:shellies/shelly4pro-061D51/relay/2:off
2018.10.07 13:23:08 4: mqtt_192.168.0.170_61038 shelly4pro-061D51 PUBLISH shellies/shelly4pro-061D51/relay/3:off
2018.10.07 13:23:08 5: mqtt: dispatch shelly4pro_061D51:shellies/shelly4pro-061D51/relay/3:off
2018.10.07 13:23:08 4: mqtt_192.168.0.170_61038 shelly4pro-061D51 SUBSCRIBE
2018.10.07 13:23:08 4:   topic:shellies/shelly4pro-061D51/relay/3/command qos:1
2018.10.07 13:23:08 4: mqtt_192.168.0.170_61038 shelly4pro-061D51 SUBSCRIBE
2018.10.07 13:23:08 4:   topic:shellies/shelly4pro-061D51/relay/2/command qos:1
2018.10.07 13:23:08 4: mqtt_192.168.0.170_61038 shelly4pro-061D51 SUBSCRIBE
2018.10.07 13:23:08 4:   topic:shellies/shelly4pro-061D51/relay/1/command qos:1
2018.10.07 13:23:08 4: mqtt_192.168.0.170_61038 shelly4pro-061D51 SUBSCRIBE
2018.10.07 13:23:08 4:   topic:shellies/shelly4pro-061D51/relay/0/command qos:1
2018.10.07 13:23:13 5: mqtt_192.168.0.170_61038 shelly4pro-061D51 => shellies/shelly4pro-061D51/relay/0/command:off
2018.10.07 13:23:13 1: M2: Unhandled packet PUBACK, disconneting mqtt_192.168.0.170_61038
2018.10.07 13:23:15 4: Connection accepted from mqtt_192.168.0.170_63638
2018.10.07 13:23:15 4: mqtt_192.168.0.170_63638 shelly4pro-061D51 CONNECT V:4 keepAlive:60
2018.10.07 13:23:15 4: mqtt_192.168.0.170_63638 shelly4pro-061D51 PUBLISH shellies/shelly4pro-061D51/relay/0:off
2018.10.07 13:23:15 5: mqtt: dispatch shelly4pro_061D51:shellies/shelly4pro-061D51/relay/0:off
2018.10.07 13:23:15 4: mqtt_192.168.0.170_63638 shelly4pro-061D51 PUBLISH shellies/shelly4pro-061D51/relay/1:off
2018.10.07 13:23:15 5: mqtt: dispatch shelly4pro_061D51:shellies/shelly4pro-061D51/relay/1:off
2018.10.07 13:23:15 4: mqtt_192.168.0.170_63638 shelly4pro-061D51 PUBLISH shellies/shelly4pro-061D51/relay/2:off
2018.10.07 13:23:15 5: mqtt: dispatch shelly4pro_061D51:shellies/shelly4pro-061D51/relay/2:off
2018.10.07 13:23:15 4: mqtt_192.168.0.170_63638 shelly4pro-061D51 PUBLISH shellies/shelly4pro-061D51/relay/3:off
2018.10.07 13:23:15 5: mqtt: dispatch shelly4pro_061D51:shellies/shelly4pro-061D51/relay/3:off
2018.10.07 13:23:15 4: mqtt_192.168.0.170_63638 shelly4pro-061D51 SUBSCRIBE
2018.10.07 13:23:15 4:   topic:shellies/shelly4pro-061D51/relay/3/command qos:1
2018.10.07 13:23:15 4: mqtt_192.168.0.170_63638 shelly4pro-061D51 SUBSCRIBE
2018.10.07 13:23:15 4:   topic:shellies/shelly4pro-061D51/relay/2/command qos:1
2018.10.07 13:23:15 4: mqtt_192.168.0.170_63638 shelly4pro-061D51 SUBSCRIBE
2018.10.07 13:23:15 4:   topic:shellies/shelly4pro-061D51/relay/1/command qos:1
2018.10.07 13:23:15 4: mqtt_192.168.0.170_63638 shelly4pro-061D51 SUBSCRIBE
2018.10.07 13:23:15 4:   topic:shellies/shelly4pro-061D51/relay/0/command qos:1

LG

pah
« Letzte Änderung: 07 Oktober 2018, 13:26:56 von Prof. Dr. Peter Henning »

Offline rudolfkoenig

  • Administrator
  • Hero Member
  • *****
  • Beiträge: 19485
Antw:[Bugs] 00_MQTT2_SERVER / 10_MQTT2_DEVICE
« Antwort #155 am: 07 Oktober 2018, 23:11:33 »
Sorry, nachtraeglich modifizierte Beitraege uebersehe ich fast immer, da ich keine Email-Nachricht bekomme.

autocreate wird aufgerufen, falls das Attribut in MQTT2_SERVER gesetzt ist, kein MQTT2_DEVICE den betroffenen Topic per readingsList "abonniert", und noch kein Geraet mit diesem clientId angelegt ist. Da bei der Umbenennung clientId nicht verlorengeht, und alle dispatch Meldungen mit dem im define spezifizierten clientId (shelly4pro_061D51) erstellt wurden, sehe ich keinen Grund fuer autocreate.

Ich brauche zum Nachweis das Log mit "attr mqtt autocreate 1".Wurde FHEM nach dem Umbenennen neu gestartet?Es sollte mit und ohne funktionieren, ich will es nur beim debuggen leichter haben.

Offline kadettilac89

  • Sr. Member
  • ****
  • Beiträge: 813
Antw:[Bugs] 00_MQTT2_SERVER / 10_MQTT2_DEVICE
« Antwort #156 am: 12 Oktober 2018, 10:52:31 »
Ich habe mal zum Test das Server / Broker-Modul eingebunden. Sobald ich eine Msg pushe crasht Fhem (Connection lost ... retry 5 seconds).

Verbose 5 ist gesetzt, Log ist aber ohne Eintrag ... nur dass Fhem neu gestartet wurde, und der Reconnect des MQTT-Clients

Gibt es zu Perl irgendwo noch Logs in denen ich nachsehen kann was genau abgebrochen ist? In /var/log gibt es keine Datei die zum Zeitpunkt des (der) Abbrüche geändert wurde.

Definition
defmod MQTT MQTT2_SERVER 8090 global
attr MQTT autocreate 1
attr MQTT room Test
attr MQTT verbose 5

setstate MQTT 2018-10-12 10:45:03 nrclients 1
setstate MQTT 2018-10-12 10:44:40 state Initialized

SystemD Log
Okt 12 10:44:22 raspfhem.home systemd[1]: fhem.service: Main process exited, code=exited, status=255/n/a
Okt 12 10:44:22 raspfhem.home systemd[1]: fhem.service: Unit entered failed state.
Okt 12 10:44:22 raspfhem.home systemd[1]: fhem.service: Failed with result 'exit-code'.
Okt 12 10:44:27 raspfhem.home systemd[1]: fhem.service: Service hold-off time over, scheduling restart.
Okt 12 10:44:27 raspfhem.home systemd[1]: Stopped FHEM Home Automation.
Okt 12 10:44:27 raspfhem.home systemd[1]: Starting FHEM Home Automation...

Perl  "This is perl 5, version 24, subversion 1 (v5.24.1) built for arm-linux-gnueabihf-thread-multi-64int"
Raspbian aktuellste Version
Raspberry PI 3
Fhem aktuellste Version

Offline rudolfkoenig

  • Administrator
  • Hero Member
  • *****
  • Beiträge: 19485
Antw:[Bugs] 00_MQTT2_SERVER / 10_MQTT2_DEVICE
« Antwort #157 am: 12 Oktober 2018, 11:49:54 »
Starte FHEM im Terminal mit "perl fhem.pl -d fhem.cfg"

Offline kadettilac89

  • Sr. Member
  • ****
  • Beiträge: 813
Antw:[Bugs] 00_MQTT2_SERVER / 10_MQTT2_DEVICE
« Antwort #158 am: 12 Oktober 2018, 14:34:36 »
Starte FHEM im Terminal mit "perl fhem.pl -d fhem.cfg"

2 Mal getestet:
topic: test

2018.10.12 14:05:54.291 4: Connection accepted from MQTT_192.168.0.46_56856
2018.10.12 14:05:54.293 5: Starting notify loop for MQTT, 1 event(s), first is nrclients: 1
2018.10.12 14:05:54.293 5: createNotifyHash
2018.10.12 14:05:54.304 5: ----------------------------------------
2018.10.12 14:05:54.305 5: myMSwitch: eingehendes Event von -> MQTT
2018.10.12 14:05:54.305 5: ----------------------------------------
2018.10.12 14:05:54.308 4: DbLog myDbLog -> ################################################################
2018.10.12 14:05:54.308 4: DbLog myDbLog -> ###              start of new Logcycle                       ###
2018.10.12 14:05:54.308 4: DbLog myDbLog -> ################################################################
2018.10.12 14:05:54.308 4: DbLog myDbLog -> number of events received: 1 for device: MQTT
2018.10.12 14:05:54.309 4: DbLog myDbLog -> check Device: MQTT , Event: nrclients: 1
2018.10.12 14:05:54.317 5: End notify loop for MQTT
2018.10.12 14:05:54.320 4: MQTT_192.168.0.46_56856 root.1539345952240 CONNECT V:3 keepAlive:60
2018.10.12 14:05:54.823 4: MQTT_192.168.0.46_56856 root.1539345952240 SUBSCRIBE
2018.10.12 14:05:55.892 4: MQTT_192.168.0.46_56856 root.1539345952240 DISCONNECT
2018.10.12 14:05:55.893 5: Starting notify loop for MQTT, 1 event(s), first is nrclients: 0
2018.10.12 14:05:55.894 5: ----------------------------------------
2018.10.12 14:05:55.894 5: myMSwitch: eingehendes Event von -> MQTT
2018.10.12 14:05:55.894 5: ----------------------------------------
2018.10.12 14:05:55.897 4: DbLog myDbLog -> ################################################################
2018.10.12 14:05:55.897 4: DbLog myDbLog -> ###              start of new Logcycle                       ###
2018.10.12 14:05:55.897 4: DbLog myDbLog -> ################################################################
2018.10.12 14:05:55.897 4: DbLog myDbLog -> number of events received: 1 for device: MQTT
2018.10.12 14:05:55.898 4: DbLog myDbLog -> check Device: MQTT , Event: nrclients: 0
2018.10.12 14:05:55.905 5: End notify loop for MQTT
2018.10.12 14:05:56.085 4: Connection accepted from MQTT_192.168.0.46_56860
2018.10.12 14:05:56.086 5: Starting notify loop for MQTT, 1 event(s), first is nrclients: 1
2018.10.12 14:05:56.087 5: ----------------------------------------
2018.10.12 14:05:56.087 5: myMSwitch: eingehendes Event von -> MQTT
2018.10.12 14:05:56.087 5: ----------------------------------------
2018.10.12 14:05:56.090 4: DbLog myDbLog -> ################################################################
2018.10.12 14:05:56.090 4: DbLog myDbLog -> ###              start of new Logcycle                       ###
2018.10.12 14:05:56.090 4: DbLog myDbLog -> ################################################################
2018.10.12 14:05:56.090 4: DbLog myDbLog -> number of events received: 1 for device: MQTT
2018.10.12 14:05:56.090 4: DbLog myDbLog -> check Device: MQTT , Event: nrclients: 1
2018.10.12 14:05:56.098 5: End notify loop for MQTT
2018.10.12 14:05:56.100 4: MQTT_192.168.0.46_56860 root.1539345953808 CONNECT V:3 keepAlive:60
2018.10.12 14:06:05.858 4: MQTT_192.168.0.46_56860 root.1539345953808 PUBLISH test:abc
2018.10.12 14:06:05.859 5: MQTT: dispatch autocreate:root.1539345953808:test:abc
2018.10.12 14:06:05.914 5: Loading ./FHEM/10_MQTT2_DEVICE.pm
2018.10.12 14:06:05.938 5: Starting notify loop for global, 1 event(s), first is UNDEFINED MQTT2_root.1539345953808 MQTT2_DEVICE root.1539345953808
2018.10.12 14:06:05.938 5: ----------------------------------------
2018.10.12 14:06:05.938 5: myMSwitch: eingehendes Event von -> global
2018.10.12 14:06:05.938 5: ----------------------------------------
2018.10.12 14:06:05.942 4: DbLog myDbLog -> ################################################################
2018.10.12 14:06:05.942 4: DbLog myDbLog -> ###              start of new Logcycle                       ###
2018.10.12 14:06:05.942 4: DbLog myDbLog -> ################################################################
2018.10.12 14:06:05.942 4: DbLog myDbLog -> number of events received: 1 for device: global
2018.10.12 14:06:05.942 4: DbLog myDbLog -> check Device: global , Event: UNDEFINED MQTT2_root.1539345953808 MQTT2_DEVICE root.1539345953808
2018.10.12 14:06:05.958 5: End notify loop for global
2018.10.12 14:06:05.958 5: Starting notify loop for MQTT, 1 event(s), first is test:abc
2018.10.12 14:06:05.958 5: ----------------------------------------
2018.10.12 14:06:05.958 5: myMSwitch: eingehendes Event von -> MQTT
2018.10.12 14:06:05.958 5: ----------------------------------------
2018.10.12 14:06:05.960 4: DbLog myDbLog -> ################################################################
2018.10.12 14:06:05.960 4: DbLog myDbLog -> ###              start of new Logcycle                       ###
2018.10.12 14:06:05.960 4: DbLog myDbLog -> ################################################################
2018.10.12 14:06:05.960 4: DbLog myDbLog -> number of events received: 1 for device: MQTT
2018.10.12 14:06:05.960 4: DbLog myDbLog -> check Device: MQTT , Event: test:abc
2018.10.12 14:06:05.964 5: End notify loop for MQTT

myMSwitch habe ich disabled da es kurz vor dem Absturz abgearbeitet wurde

2018.10.12 14:19:51.147 4: Connection accepted from MQTT_192.168.0.46_57042
2018.10.12 14:19:51.149 5: Starting notify loop for MQTT, 1 event(s), first is nrclients: 1
2018.10.12 14:19:51.149 5: createNotifyHash
2018.10.12 14:19:51.171 4: DbLog myDbLog -> ################################################################
2018.10.12 14:19:51.171 4: DbLog myDbLog -> ###              start of new Logcycle                       ###
2018.10.12 14:19:51.171 4: DbLog myDbLog -> ################################################################
2018.10.12 14:19:51.171 4: DbLog myDbLog -> number of events received: 1 for device: MQTT
2018.10.12 14:19:51.172 4: DbLog myDbLog -> check Device: MQTT , Event: nrclients: 1
2018.10.12 14:19:51.182 5: End notify loop for MQTT
2018.10.12 14:19:51.185 4: MQTT_192.168.0.46_57042 root.1539346789386 CONNECT V:3 keepAlive:60
2018.10.12 14:19:51.197 4: MQTT_192.168.0.46_57042 root.1539346789386 SUBSCRIBE
2018.10.12 14:19:53.553 4: MQTT_192.168.0.46_57042 root.1539346789386 DISCONNECT
2018.10.12 14:19:53.555 5: Starting notify loop for MQTT, 1 event(s), first is nrclients: 0
2018.10.12 14:19:53.558 4: DbLog myDbLog -> ################################################################
2018.10.12 14:19:53.559 4: DbLog myDbLog -> ###              start of new Logcycle                       ###
2018.10.12 14:19:53.559 4: DbLog myDbLog -> ################################################################
2018.10.12 14:19:53.559 4: DbLog myDbLog -> number of events received: 1 for device: MQTT
2018.10.12 14:19:53.560 4: DbLog myDbLog -> check Device: MQTT , Event: nrclients: 0
2018.10.12 14:19:53.569 5: End notify loop for MQTT
2018.10.12 14:19:53.573 4: Connection accepted from MQTT_192.168.0.46_57056
2018.10.12 14:19:53.574 5: Starting notify loop for MQTT, 1 event(s), first is nrclients: 1
2018.10.12 14:19:53.577 4: DbLog myDbLog -> ################################################################
2018.10.12 14:19:53.577 4: DbLog myDbLog -> ###              start of new Logcycle                       ###
2018.10.12 14:19:53.577 4: DbLog myDbLog -> ################################################################
2018.10.12 14:19:53.577 4: DbLog myDbLog -> number of events received: 1 for device: MQTT
2018.10.12 14:19:53.578 4: DbLog myDbLog -> check Device: MQTT , Event: nrclients: 1
2018.10.12 14:19:53.587 5: End notify loop for MQTT
2018.10.12 14:19:53.589 4: MQTT_192.168.0.46_57056 root.1539346791825 CONNECT V:3 keepAlive:60
2018.10.12 14:19:58.646 4: MQTT_192.168.0.46_57056 root.1539346791825 PUBLISH test:hhz
2018.10.12 14:19:58.647 5: MQTT: dispatch autocreate:root.1539346791825:test:hhz
2018.10.12 14:19:58.713 5: Loading ./FHEM/10_MQTT2_DEVICE.pm
2018.10.12 14:19:58.738 5: Starting notify loop for global, 1 event(s), first is UNDEFINED MQTT2_root.1539346791825 MQTT2_DEVICE root.1539346791825
2018.10.12 14:19:58.742 4: DbLog myDbLog -> ################################################################
2018.10.12 14:19:58.742 4: DbLog myDbLog -> ###              start of new Logcycle                       ###
2018.10.12 14:19:58.742 4: DbLog myDbLog -> ################################################################
2018.10.12 14:19:58.742 4: DbLog myDbLog -> number of events received: 1 for device: global
2018.10.12 14:19:58.742 4: DbLog myDbLog -> check Device: global , Event: UNDEFINED MQTT2_root.1539346791825 MQTT2_DEVICE root.1539346791825
2018.10.12 14:19:58.758 5: End notify loop for global
2018.10.12 14:19:58.759 5: Starting notify loop for MQTT, 1 event(s), first is test:hhz
2018.10.12 14:19:58.760 4: DbLog myDbLog -> ################################################################
2018.10.12 14:19:58.760 4: DbLog myDbLog -> ###              start of new Logcycle                       ###
2018.10.12 14:19:58.760 4: DbLog myDbLog -> ################################################################
2018.10.12 14:19:58.760 4: DbLog myDbLog -> number of events received: 1 for device: MQTT
2018.10.12 14:19:58.761 4: DbLog myDbLog -> check Device: MQTT , Event: test:hhz
2018.10.12 14:19:58.765 5: End notify loop for MQTT

Offline rudolfkoenig

  • Administrator
  • Hero Member
  • *****
  • Beiträge: 19485
Antw:[Bugs] 00_MQTT2_SERVER / 10_MQTT2_DEVICE
« Antwort #159 am: 12 Oktober 2018, 16:31:52 »
Ich kann da keine Probleme entdecken. Hat sich FHEM auch diesmal beendet?

Wenn ja, dann bitte in FHEM/00_MQTT2_SERVER.pm die Zeilen unter "#Lowlevel debugging" aktivieren, und das Problem erneut mit "perl fhem.pl -d fhem.cfg" reproduzieren.

Offline kadettilac89

  • Sr. Member
  • ****
  • Beiträge: 813
Antw:[Bugs] 00_MQTT2_SERVER / 10_MQTT2_DEVICE
« Antwort #160 am: 12 Oktober 2018, 17:22:04 »
Ich kann da keine Probleme entdecken. Hat sich FHEM auch diesmal beendet?

Wenn ja, dann bitte in FHEM/00_MQTT2_SERVER.pm die Zeilen unter "#Lowlevel debugging" aktivieren, und das Problem erneut mit "perl fhem.pl -d fhem.cfg" reproduzieren.

hätte ich dazu schreiben können, ja, auch mit deaktiviertem MSwitch crasht Fhem

Einkommentierte Zeilen ...
  # Lowlevel debugging
   my $pltxt = $pl;
   $pltxt =~ s/([^ -~])/"(".ord($1).")"/ge;
   Log3 $sname, 5, "$pltxt";

Nun 2 weitere Test, jedesmal endet es mit Crash

selber Test wie vorher ....

2018.10.12 16:50:25.467 4: Connection accepted from MQTT_192.168.0.46_59000
2018.10.12 16:50:25.468 5: Starting notify loop for MQTT, 1 event(s), first is nrclients: 1
2018.10.12 16:50:25.471 4: DbLog myDbLog -> ################################################################
2018.10.12 16:50:25.471 4: DbLog myDbLog -> ###              start of new Logcycle                       ###
2018.10.12 16:50:25.472 4: DbLog myDbLog -> ################################################################
2018.10.12 16:50:25.472 4: DbLog myDbLog -> number of events received: 1 for device: MQTT
2018.10.12 16:50:25.472 4: DbLog myDbLog -> check Device: MQTT , Event: nrclients: 1
2018.10.12 16:50:25.481 5: End notify loop for MQTT
2018.10.12 16:50:25.483 5: (0)(6)MQIsdp(3)(2)(0)<(0)(18)root.1539355822256
2018.10.12 16:50:25.484 4: MQTT_192.168.0.46_59000 root.1539355822256 CONNECT V:3 keepAlive:60
2018.10.12 16:50:25.498 5: (0)(1)(0)(4)test(1)
2018.10.12 16:50:25.498 4: MQTT_192.168.0.46_59000 root.1539355822256 SUBSCRIBE
2018.10.12 16:50:25.498 4:   topic:test qos:1
2018.10.12 16:50:35.484 5: IP: 192.168.0.36 -> 192.168.0.36
2018.10.12 16:50:36.325 5: (0)(8)test/abcmsg
2018.10.12 16:50:36.326 4: MQTT_192.168.0.46_59000 root.1539355822256 PUBLISH test/abc:msg
2018.10.12 16:50:36.326 5: MQTT: dispatch autocreate:root.1539355822256:test/abc:msg
2018.10.12 16:50:36.392 5: Loading ./FHEM/10_MQTT2_DEVICE.pm
2018.10.12 16:50:36.416 5: Starting notify loop for global, 1 event(s), first is UNDEFINED MQTT2_root.1539355822256 MQTT2_DEVICE root.1539355822256
2018.10.12 16:50:36.420 4: DbLog myDbLog -> ################################################################
2018.10.12 16:50:36.420 4: DbLog myDbLog -> ###              start of new Logcycle                       ###
2018.10.12 16:50:36.420 4: DbLog myDbLog -> ################################################################
2018.10.12 16:50:36.420 4: DbLog myDbLog -> number of events received: 1 for device: global
2018.10.12 16:50:36.420 4: DbLog myDbLog -> check Device: global , Event: UNDEFINED MQTT2_root.1539355822256 MQTT2_DEVICE root.1539355822256
2018.10.12 16:50:36.437 5: End notify loop for global
2018.10.12 16:50:36.437 5: Starting notify loop for MQTT, 1 event(s), first is test/abc:msg
2018.10.12 16:50:36.439 4: DbLog myDbLog -> ################################################################
2018.10.12 16:50:36.439 4: DbLog myDbLog -> ###              start of new Logcycle                       ###
2018.10.12 16:50:36.439 4: DbLog myDbLog -> ################################################################
2018.10.12 16:50:36.439 4: DbLog myDbLog -> number of events received: 1 for device: MQTT
2018.10.12 16:50:36.439 4: DbLog myDbLog -> check Device: MQTT , Event: test/abc:msg
2018.10.12 16:50:36.443 5: End notify loop for MQTT


deaktiviertes DBLog (attr. disable 1)

ich weiß, dass syslog oder Thermostate erstmal nichts damit zu tun haben, ich habe aus dem Log nichts gelöscht ...

2018.10.12 17:01:07.105 4: Connection accepted from MQTT_192.168.0.46_59194
2018.10.12 17:01:07.106 5: Starting notify loop for MQTT, 1 event(s), first is nrclients: 1
2018.10.12 17:01:07.106 5: createNotifyHash
2018.10.12 17:01:07.132 5: End notify loop for MQTT
2018.10.12 17:01:07.134 5: (0)(6)MQIsdp(3)(2)(0)<(0)(18)root.1539356465317
2018.10.12 17:01:07.135 4: MQTT_192.168.0.46_59194 root.1539356465317 CONNECT V:3 keepAlive:60
2018.10.12 17:01:07.544 5: (0)(1)(0)(4)test(1)
2018.10.12 17:01:07.545 4: MQTT_192.168.0.46_59194 root.1539356465317 SUBSCRIBE
2018.10.12 17:01:07.545 4:   topic:test qos:1
2018.10.12 17:01:13.354 5: SYSMON sysmon: updateReadings.1060
2018.10.12 17:01:13.370 4: BlockingCall (SYSMON_blockingCall): created child (20322), uses telnetPort to connect back
2018.10.12 17:01:13.390 4: Connection accepted from telnetPort_127.0.0.1_50432
2018.10.12 17:01:13.394 5: Cmd: >{BlockingRegisterTelnet($cl,14)}<
2018.10.12 17:01:13.397 5: SYSMON sysmon: blockingCall.954 sysmon,
2018.10.12 17:01:13.398 5: SYSMON sysmon: Exec_Local.4151 Execute '[ -d /proc/ ] && echo 1 || echo 0'
2018.10.12 17:01:13.427 5: SYSMON sysmon: Exec_Local.4164 Result '1'
2018.10.12 17:01:13.428 5: SYSMON sysmon: Exec_Local.4151 Execute 'cat /proc/uptime'
2018.10.12 17:01:13.457 5: SYSMON sysmon: Exec_Local.4164 Result '24443.78 95789.40'
2018.10.12 17:01:13.457 5: SYSMON sysmon: Exec_Local.4151 Execute 'cat /proc/stat|grep 'cpu ''
2018.10.12 17:01:13.495 5: SYSMON sysmon: Exec_Local.4164 Result 'cpu  121441 778 48041 9427590 16082 0 11023 0 0 0'
2018.10.12 17:01:13.496 5: SYSMON sysmon: Exec_Local.4151 Execute '[ -f /sys/devices/system/cpu/kernel_max ] && echo 1 || echo 0'
2018.10.12 17:01:13.524 5: SYSMON sysmon: Exec_Local.4164 Result '1'
2018.10.12 17:01:13.525 5: SYSMON sysmon: Exec_Local.4151 Execute 'cat /sys/devices/system/cpu/kernel_max'
2018.10.12 17:01:13.554 5: SYSMON sysmon: Exec_Local.4164 Result '3'
2018.10.12 17:01:13.556 5: SYSMON sysmon: obtainParameters_intern.1350 User-Defined Reading: [certExpires][720][certExpires][cat /opt/fhem/log/cert_age.txt]
2018.10.12 17:01:13.556 5: SYSMON sysmon: obtainParameters_intern.1358 User-Defined Reading: [certExpires][720][certExpires][cat /opt/fhem/log/cert_age.txt] out of refresh interval
2018.10.12 17:01:13.556 5: SYSMON sysmon: obtainParameters_intern.1350 User-Defined Reading: [updateStatus][720][updateStatus][cat /opt/fhem/log/updatestatus.txt | head -n1]
2018.10.12 17:01:13.556 5: SYSMON sysmon: obtainParameters_intern.1358 User-Defined Reading: [updateStatus][720][updateStatus][cat /opt/fhem/log/updatestatus.txt | head -n1] out of refresh interval
2018.10.12 17:01:13.556 5: SYSMON sysmon: obtainParameters_intern.1350 User-Defined Reading: [updateStatusList][720][updateStatusList][cat /opt/fhem/log/updatestatus.txt | tail -n +3]
2018.10.12 17:01:13.556 5: SYSMON sysmon: obtainParameters_intern.1358 User-Defined Reading: [updateStatusList][720][updateStatusList][cat /opt/fhem/log/updatestatus.txt | tail -n +3] out of refresh interval
2018.10.12 17:01:13.557 5: SYSMON sysmon: obtainParameters_intern.1372 User-Defined Fn: [backupAge][720]
2018.10.12 17:01:13.557 5: SYSMON sysmon: obtainParameters_intern.1380 User-Defined Fn: [backupAge][720] out of refresh interval
2018.10.12 17:01:13.558 5: Cmd: >{BlockingStart('14')}<
2018.10.12 17:01:13.562 5: Cmd: >{SYSMON_blockingFinish('name|sysmon|uptime|24443|fhemuptime_text|0 days, 00 hours, 01 minutes|fhemstarttime|1539356354|uptime_text|0 days, 06 hours, 47 minutes|starttime|1539332029|starttime_text|12.10.2018 10:13:49|idletime|23568 96.42 %|fhemstarttime_text|12.10.2018 16:59:14|idletime_text|0 days, 06 hours, 32 minutes (96.42 %)|fhemuptime|119')}<
2018.10.12 17:01:13.563 5: SYSMON sysmon: blockingFinish.1041 name|sysmon|uptime|24443|fhemuptime_text|0 days, 00 hours, 01 minutes|fhemstarttime|1539356354|uptime_text|0 days, 06 hours, 47 minutes|starttime|1539332029|starttime_text|12.10.2018 10:13:49|idletime|23568 96.42 %|fhemstarttime_text|12.10.2018 16:59:14|idletime_text|0 days, 06 hours, 32 minutes (96.42 %)|fhemuptime|119
2018.10.12 17:01:13.563 5: SYSMON sysmon: updateReadings.1060
2018.10.12 17:01:16.896 5: (0)(8)test/abcmsg
2018.10.12 17:01:16.896 4: MQTT_192.168.0.46_59194 root.1539356465317 PUBLISH test/abc:msg
2018.10.12 17:01:16.897 5: MQTT: dispatch autocreate:root.1539356465317:test/abc:msg
2018.10.12 17:01:16.955 5: Loading ./FHEM/10_MQTT2_DEVICE.pm
2018.10.12 17:01:16.990 5: Starting notify loop for global, 1 event(s), first is UNDEFINED MQTT2_root.1539356465317 MQTT2_DEVICE root.1539356465317
2018.10.12 17:01:16.998 4: wp_schlafzimmer(getDeviceType): dy_Reboot is not supported
2018.10.12 17:01:16.998 4: wp_schlafzimmer(getDeviceType): Heizung_Wohnzimmer, model HM-CC-RT-DN has no chanNo
2018.10.12 17:01:16.998 4: wp_schlafzimmer(getDeviceType): Programm_SZ is not supported
2018.10.12 17:01:16.998 5: wp_schlafzimmer(getDeviceType): Heizung_Schlafzimmer_WindowRec, HM-CC-RT-DN, 3
2018.10.12 17:01:16.998 4: wp_schlafzimmer(getDeviceType): Heizung_Schlafzimmer_WindowRec is not supported
2018.10.12 17:01:16.999 5: wp_schlafzimmer(getDeviceType): Heizung_Wohnzimmer_Clima, HM-CC-RT-DN, 4
2018.10.12 17:01:16.999 4: wp_schlafzimmer(getDeviceType): Heizung_Wohnzimmer_Clima is type CUL_HM
2018.10.12 17:01:16.999 4: wp_schlafzimmer(getDeviceType): dy_test1 is not supported
2018.10.12 17:01:16.999 4: wp_schlafzimmer(getDeviceType): HMTempSensor2, model HB-UNI-Sensor1 is not supported
2018.10.12 17:01:16.999 4: wp_schlafzimmer(getDeviceType): dy_eventlog is not supported
2018.10.12 17:01:16.999 5: wp_schlafzimmer(getDeviceType): Heizung_Schlafzimmer_Climate, HM-CC-RT-DN, 2
2018.10.12 17:01:16.999 4: wp_schlafzimmer(getDeviceType): Heizung_Schlafzimmer_Climate is not supported
2018.10.12 17:01:16.999 4: wp_schlafzimmer(getDeviceType): TVTimer is not supported
2018.10.12 17:01:17.000 4: wp_schlafzimmer(getDeviceType): Programm_WZ is not supported
2018.10.12 17:01:17.000 5: wp_schlafzimmer(getDeviceType): Heizung_Schlafzimmer_ClimaTeam, HM-CC-RT-DN, 5
2018.10.12 17:01:17.000 4: wp_schlafzimmer(getDeviceType): Heizung_Schlafzimmer_ClimaTeam is not supported
2018.10.12 17:01:17.000 4: wp_schlafzimmer(getDeviceType): ActionDetector, model ActionDetector is not supported
2018.10.12 17:01:17.000 5: wp_schlafzimmer(getDeviceType): Heizung_Schlafzimmer_Clima, HM-CC-RT-DN, 4
2018.10.12 17:01:17.000 4: wp_schlafzimmer(getDeviceType): Heizung_Schlafzimmer_Clima is type CUL_HM
2018.10.12 17:01:17.000 4: wp_schlafzimmer(getDeviceType): HMTempSensor4, model HB-UNI-Sensor1 is not supported
2018.10.12 17:01:17.001 4: wp_schlafzimmer(getDeviceType): dy_test3 is not supported
2018.10.12 17:01:17.001 5: wp_schlafzimmer(getDeviceType): Heizung_Schlafzimmer_remote, HM-CC-RT-DN, 6
2018.10.12 17:01:17.001 4: wp_schlafzimmer(getDeviceType): Heizung_Schlafzimmer_remote is not supported
2018.10.12 17:01:17.001 4: wp_schlafzimmer(getDeviceType): dy_autocreate is not supported
2018.10.12 17:01:17.001 4: wp_schlafzimmer(getDeviceType): dy_daylight is not supported
2018.10.12 17:01:17.001 4: wp_schlafzimmer(getDeviceType): dy_Dimmer is not supported
2018.10.12 17:01:17.001 4: wp_schlafzimmer(getDeviceType): dy_GHome is not supported
2018.10.12 17:01:17.002 4: wp_schlafzimmer(getDeviceType): dy_test2 is not supported
2018.10.12 17:01:17.002 4: wp_schlafzimmer(getDeviceType): wp_wohnzimmer is type WEEKPROFILE
2018.10.12 17:01:17.002 4: wp_schlafzimmer(getDeviceType): hm_door1, model HM-SEC-RHS is not supported
2018.10.12 17:01:17.002 4: wp_schlafzimmer(getDeviceType): dy_Dimmer2 is not supported
2018.10.12 17:01:17.002 4: wp_schlafzimmer(getDeviceType): HMTempSensor3, model HB-UNI-Sensor1 is not supported
2018.10.12 17:01:17.003 4: wp_schlafzimmer(getDeviceType): Heizung_Schlafzimmer, model HM-CC-RT-DN has no chanNo
2018.10.12 17:01:17.003 4: wp_schlafzimmer(getDeviceType): dy_Farbwechsel is not supported
2018.10.12 17:01:17.003 4: wp_schlafzimmer(getDeviceType): dy_Kodi is not supported
2018.10.12 17:01:17.003 5: wp_schlafzimmer(getDeviceType): Heizung_Schlafzimmer_Weather, HM-CC-RT-DN, 1
2018.10.12 17:01:17.003 4: wp_schlafzimmer(getDeviceType): Heizung_Schlafzimmer_Weather is not supported
2018.10.12 17:01:17.007 5: End notify loop for global
2018.10.12 17:01:17.007 5: Starting notify loop for MQTT, 1 event(s), first is test/abc:msg
2018.10.12 17:01:17.012 5: End notify loop for MQTT

Um es weiter einzugrenzen habe ich Fhem mit der Demo-Config (fhem.cfg.demo) gestartet und das Modul dort identisch eingebunden
==> KEIN Crash.

Es gibt also Abhängigkeiten zu einem anderen Modul.

Log fhem.cfg.demo (ohne Crash)
2018.10.12 17:11:44.184 4: Connection accepted from MQTT_192.168.0.46_59448
2018.10.12 17:11:44.185 5: Starting notify loop for MQTT, 1 event(s), first is nrclients: 1
2018.10.12 17:11:44.186 4: dewpoint_notify: cmd_type=dewpoint devname=MQTT dewname=dew_all, dev=MQTT, dev_regex=.* temp_name=temperature hum_name=humidity
2018.10.12 17:11:44.186 5: dewpoint_notify: s='nrclients: 1'
2018.10.12 17:11:44.186 5: dewpoint_notify: evName='nrclients:' val=1'
2018.10.12 17:11:44.186 5: dewpoint max_timediff=1
2018.10.12 17:11:44.190 5: End notify loop for MQTT
2018.10.12 17:11:44.191 5: (0)(6)MQIsdp(3)(2)(0)<(0)(18)root.1539357102436
2018.10.12 17:11:44.191 4: MQTT_192.168.0.46_59448 root.1539357102436 CONNECT V:3 keepAlive:60
2018.10.12 17:11:44.207 5: (0)(1)(0)(4)test(1)
2018.10.12 17:11:44.207 4: MQTT_192.168.0.46_59448 root.1539357102436 SUBSCRIBE
2018.10.12 17:11:44.207 4:   topic:test qos:1
2018.10.12 17:11:54.764 5: (0)(8)test/abcmsg
2018.10.12 17:11:54.765 4: MQTT_192.168.0.46_59448 root.1539357102436 PUBLISH test/abc:msg
2018.10.12 17:11:54.765 5: MQTT: dispatch autocreate:root.1539357102436:test/abc:msg
2018.10.12 17:11:54.824 5: Starting notify loop for global, 1 event(s), first is UNDEFINED MQTT2_root.1539357102436 MQTT2_DEVICE root.1539357102436
2018.10.12 17:11:54.825 4: dewpoint_notify: cmd_type=dewpoint devname=global dewname=dew_all, dev=global, dev_regex=.* temp_name=temperature hum_name=humidity
2018.10.12 17:11:54.825 5: dewpoint_notify: s='UNDEFINED MQTT2_root.1539357102436 MQTT2_DEVICE root.1539357102436'
2018.10.12 17:11:54.825 5: dewpoint_notify: evName='UNDEFINED' val=MQTT2_root.1539357102436'
2018.10.12 17:11:54.825 5: dewpoint max_timediff=1
2018.10.12 17:11:54.828 2: autocreate: define MQTT2_root.1539357102436 MQTT2_DEVICE root.1539357102436
2018.10.12 17:11:54.849 5: End notify loop for global
2018.10.12 17:11:54.850 5: Starting notify loop for global, 1 event(s), first is ATTR MQTT2_root.1539357102436 readingList root.1539357102436:test/abc:.* abc
2018.10.12 17:11:54.850 5: createNotifyHash
2018.10.12 17:11:54.852 4: dewpoint_notify: cmd_type=dewpoint devname=global dewname=dew_all, dev=global, dev_regex=.* temp_name=temperature hum_name=humidity
2018.10.12 17:11:54.852 5: dewpoint_notify: s='ATTR MQTT2_root.1539357102436 readingList root.1539357102436:test/abc:.* abc'
2018.10.12 17:11:54.852 5: dewpoint_notify: evName='ATTR' val=MQTT2_root.1539357102436'
2018.10.12 17:11:54.852 5: dewpoint max_timediff=1
2018.10.12 17:11:54.855 5: End notify loop for global
2018.10.12 17:11:54.856 4: MQTT2_DEVICE_Parse: MQTT2_root.1539357102436 test/abc => abc
2018.10.12 17:11:54.856 5: Starting notify loop for MQTT2_root.1539357102436, 1 event(s), first is abc: msg
2018.10.12 17:11:54.856 4: dewpoint_notify: cmd_type=dewpoint devname=MQTT2_root.1539357102436 dewname=dew_all, dev=MQTT2_root.1539357102436, dev_regex=.* temp_name=temperature hum_name=humidity
2018.10.12 17:11:54.856 5: dewpoint_notify: s='abc: msg'
2018.10.12 17:11:54.856 5: dewpoint_notify: evName='abc:' val=msg'
2018.10.12 17:11:54.857 5: dewpoint max_timediff=1
2018.10.12 17:11:54.858 5: End notify loop for MQTT2_root.1539357102436


Hier meine Module ... alle ohne explizite Namen haben mehr als 2 Devices, wollte die Liste nicht zu lange machen
Global:
  global               (no definition)

CUL:

MQTT2_SERVER:
  MQTT                 (Initialized)

FHEMWEB:

HTTPSRV:
  TABLETUI             (TABLETUI)

CUL_HM:

IT:

RESIDENTS:
  Residents            (home)

CUL_TCM97001:
  TempSensor1          (T: 19.1 H: 52)

ROOMMATE:

EspLedController:
  LED_rgb              (disconnected)

speedtest:
  speedtest            (Initialized)

readingsChange:
  rc_test1             (active)

readingsGroup:

ESPEasy:

Spotify:
  Spotify              (connected)

SYSMON:
  sysmon               (Initialized)
  sysmon_BPI           (Inactive)

CALVIEW:
  myFhemCal_view       (t: 5 td: 0 tm: 0)

Calendar:
  myFhemCal            (triggered)

Twilight:
  twilight             (6)

Weather:

ENIGMA2:
  enigma2              (absent)

KODI:
  kodi                 (Initialized)

Pushover:
  pushover             (disconnected)

PRESENCE:

at:

eventTypes:
  eventTypes           (active)

notify:

watchdog:

FileLog:

DbLog:
  myDbLog              (connected)

DbRep:
  myDbRep              (connected)
  myDbRepAgent         (connected » ProcTime: 0.0014 sec)

remotecontrol:
  kodi_rc              (initialized)

allowed:
  allowed_WEBCMD       (validFor:WEBCMD)

DOIF:

GEOFANCY:
  geofancy             (initialized)

HMinfo:
  hm                   (updated:2017-04-15 11:38:35)

HMtemplate:
  ht                   (init)

MSwitch:
  myMSwitch            (off)

SVG:

WOL:

autocreate:
  autocreate           (disabled)

dummy:

freezemon:
  myFreezemon          (inactive)

structure:
  Programm             (Aus)

telnet:
  telnetPort           (Initialized)
  telnetPort_127.0.0.1_50720 (Connected)

weblink:

weekprofile:


Offline rudolfkoenig

  • Administrator
  • Hero Member
  • *****
  • Beiträge: 19485
Antw:[Bugs] 00_MQTT2_SERVER / 10_MQTT2_DEVICE
« Antwort #161 am: 13 Oktober 2018, 11:17:00 »
Zitat
Nun 2 weitere Test, jedesmal endet es mit Crash
Ich sehe leider da auch nicht mehr.

Was mir komisch vorkommt: wenn FHEM abstuerzt, dann ist entweder ein schwerwiegender Perl-Programmierfehler dran Schuld, oder ein Fehler im perl-binary oder in einen der verwendeten C-Bibliotheken. Im ersten Fall gibt das Perl-Binary auf der Konsole eine Fehlermeldung aus, im zweiten Fall das Betriebsystem bzw. der Shell, von wo man perl gestartet hat. In deinem Fall ist aber nichts davon zu sehen: startest du FHEM aus der Kommandozeile (wie ich es gedacht habe), oder schaust du nur nachtraeglich die Logs an?

Falls Kommandozeile, und keine weiteren Daten:
- bitte Prozess-Rueckgabewert nach dem FHEM-Crash ausgeben mit: echo $!
- FHEM unter strace starten, und die strace logs hier anhaengen:
strace -f -o /tmp/fhem.strace.log perl fhem.pl -d fhem.cfg

Offline kadettilac89

  • Sr. Member
  • ****
  • Beiträge: 813
Antw:[Bugs] 00_MQTT2_SERVER / 10_MQTT2_DEVICE
« Antwort #162 am: 13 Oktober 2018, 11:42:33 »
habe direkt auf der Commandline gestartet ...

Fehler gefunden. Danke für die Unterstützung.

Apptime deaktiviert und es funktioniert. Apptime ist mir nicht wichtig, ich lasse es aus.

mit "echo $!" erscheinte folgende Ausgabe: (letzen Zeilen des Logs wie gehabt).
.....
2018.10.13 11:30:10.177 4: DbLog myDbLog -> number of events received: 1 for device: MQTT
2018.10.13 11:30:10.178 4: DbLog myDbLog -> check Device: MQTT , Event: test/ggg:vvv
2018.10.13 11:30:10.184 5: End notify loop for MQTT
fhem@raspfhem:~$ echo $!
argument is not a reference at ./FHEM/98_apptime.pm line 127.

fhem@raspfhem:~$

Sourcecode aus apptime
  if(%prioQueues) {
    my $nice = minNum(keys %prioQueues);
    my $entry = shift(@{$prioQueues{$nice}});
    delete $prioQueues{$nice} if(!@{$prioQueues{$nice}});

127 --->>    $cv = svref_2object($entry->{fn});  <<---
    $fnname = $cv->GV->NAME;
    $shortarg = (defined($entry->{arg})?$entry->{arg}:"");
    $shortarg = "HASH_unnamed" if (   (ref($shortarg) eq "HASH")
                                   && !defined($shortarg->{NAME}) );
    ($shortarg,undef) = split(/:|;/,$shortarg,2);
    apptime_getTiming("global","nice-".$fnname.";".$shortarg, $entry->{fn}, $now, $entry->{arg});

    $nextat = 1 if(%prioQueues);
  }

Offline rudolfkoenig

  • Administrator
  • Hero Member
  • *****
  • Beiträge: 19485
Antw:[Bugs] 00_MQTT2_SERVER / 10_MQTT2_DEVICE
« Antwort #163 am: 13 Oktober 2018, 12:27:00 »
argument is not a reference at ./FHEM/98_apptime.pm line 127.Das muss ich mir merken. Danke fuer dein Ausdauer!

Offline MarkusN

  • Full Member
  • ***
  • Beiträge: 224
    • Markus´ Blog
Antw:[Bugs] 00_MQTT2_SERVER / 10_MQTT2_DEVICE
« Antwort #164 am: 15 Oktober 2018, 20:19:57 »
Wie genau verhält es sich mit den retained messages? Soweit ich weiß werden retained messages gelöscht wenn FHEM neu gestartet wird. Bei mir bleibt das retained reading im MQTT2_SERVER device jedoch bestehen wenn ich fhem restarte, und auch die clients handeln entsprechend wenn sie sich mit dem Server verbinden.

 

decade-submarginal