FRM & FHEM-Crash

ThoTo · 15 Dezember 2017, 15:35:16

Hallo zusammen!

Ich nutze seit zwei Monaten FRM und OWX um 1wire-Temperatursensoren in FHEM einzubinden.
Es kam jetzt schon einige Male vor, dass mir FHEM im Betrieb abgestürzt ist, das war vor der Nutzung von FRM nicht der Fall.
Laut Logs passierte der letzte Crash gegen 09:57 Uhr, der letzte Filelogeintrag der Sensoren war um 09:53 Uhr.

FHEM Log

Code Auswählen

2017.12.15 11:03:31 3: WEB: port 8083 opened
2017.12.15 11:03:31 3: telnetPort: port 7072 opened
pin '19' is not configured for mode 'ONEWIRE' at FHEM/lib/Device/Firmata/Platform.pm line 784.
2017.12.15 09:57:08 3: CUL_HM set OGBA.HM.Beleuchtung on-for-timer 125
2017.12.15 09:56:31 1: fhem_hw:2004 reappeared (OWArduino)
2017.12.15 09:56:30 3: Firmata Firmware Version: ConfigurableFirmata.ino V_2_06
2017.12.15 09:56:30 3: querying Firmata Firmware Version
2017.12.15 09:56:29 3: querying Firmata Firmware Version
2017.12.15 09:55:27 3: no response from Firmata, closing DevIO
2017.12.15 09:55:27 3: querying Firmata Firmware Version
2017.12.15 09:55:26 3: querying Firmata Firmware Version
2017.12.15 09:55:25 3: querying Firmata Firmware Version
2017.12.15 09:55:24 3: querying Firmata Firmware Version
2017.12.15 09:55:22 1: fhem_hw:2004 disconnected, waiting to reappear (OWArduino)
2017.12.15 09:55:21 1: fhem_hw:2004 disconnected, waiting to reappear (OWArduino)
2017.12.15 09:52:00 3: CUL_HM set OGBA.HM.Beleuchtung on
2017.12.15 09:50:24 3: CUL_HM set OGBA.HM.Beleuchtung on-for-timer 125
2017.12.15 09:48:22 3: CUL_HM set OGBA.HM.Beleuchtung on
2017.12.15 09:48:09 3: CUL_HM set OGBA.HM.Beleuchtung on-for-timer 125
2017.12.15 09:44:32 3: CUL_HM set OGBA.HM.Beleuchtung on
2017.12.15 09:44:22 3: CUL_HM set OGBA.HM.Beleuchtung on-for-timer 125
2017.12.15 09:41:00 3: CUL_HM set OGBA.HM.Beleuchtung on

list OWArduino

Code Auswählen

Internals:
   CFGFN      
   DEF        fhem_hw:2004
   DeviceName fhem_hw:2004
   FD         71
   NAME       OWArduino
   NOTIFYDEV  global
   NR         219
   NTFY_ORDER 50-OWArduino
   PARTIAL    
   STATE      Initialized
   TYPE       FRM
   analog_pins 14,15,16,17,18,19,20,21
   analog_resolutions 14:10,15:10,16:10,17:10,18:10,19:10,20:10,21:10
   encoder_pins 2,3
   encoder_resolutions 2:28,3:28
   firmware   ConfigurableFirmata.ino
   firmware_version V_2_06
   i2c_pins   18,19
   input_pins 2,3,4,5,6,7,8,9,10,11,12,13,14,15,16,17,18,19
   onewire_pins 2,3,4,5,6,7,8,9,10,11,12,13,14,15,16,17,18,19
   output_pins 2,3,4,5,6,7,8,9,10,11,12,13,14,15,16,17,18,19
   pwm_pins   3,5,6,9,10,11
   pwm_resolutions 3:8,5:8,6:8,9:8,10:8,11:8
   servo_pins 2,3,4,5,6,7,8,9,10,11,12,13
   servo_resolutions 2:14,3:14,4:14,5:14,6:14,7:14,8:14,9:14,10:14,11:14,12:14,13:14
   stepper_pins 2,3,4,5,6,7,8,9,10,11,12,13,14,15,16,17,18,19
   stepper_resolutions 2:21,3:21,4:21,5:21,6:21,7:21,8:21,9:21,10:21,11:21,12:21,13:21,14:21,15:21,16:21,17:21,18:21,19:21
   READINGS:
     2017-12-15 11:03:57   state           opened
Attributes:
   group      USB Dongle
   room       System

Der Arduino ist mittels Ser2Net am Host fhem_hw eingebunden:

Code Auswählen

2004:raw:0:/dev/fhem/onewire:57600 NONE 1STOPBIT 8DATABITS HANGUP_WHEN_DONE

Es scheint dass die Verbindung zu Ser2Net verloren geht bzw. der Arduino nicht mehr ansprechbar ist.
Nach einer Minute dürfte zumindest die Verbindung wiederaufgebaut sein, aber es folgt eben der für mich nicht erklärbare FHEM-Crash.

Woran könnte das liegen?

LG Thomas

ThoTo · 20 Dezember 2017, 15:55:51

Nachdem der Maintainer des Moduls zuletzt im Oktober 2016 online war, erwarte ich mir von ihm keine Rückmeldung.
Vielleicht bringt verbose 5 etwas, ich werde den Thread dann updaten:

Code Auswählen

pin '19' is not configured for mode 'ONEWIRE' at FHEM/lib/Device/Firmata/Platform.pm line 784.
2017.12.21 06:55:16 1: fhem_hw:2004 reappeared (OWArduino)
2017.12.21 06:55:16 5: SW: f07a6807f7
2017.12.21 06:55:16 5: FRM:>f07a6807f7
2017.12.21 06:55:16 5: FRM:<7f000101010308040e070108157f000101010308040e070108157f000101010308040e070108157f00010101040e070108157f00010101040e070108157f00010101020a070108157f00010101020a070108157f00010101020a070108157f00010101020a070108157f00010101020a0601070108157f00010101020a0601070108157f020a7f020a7ff7
2017.12.21 06:55:16 5: FRM:<010815091c7f00010101040e070108157f000101010308040e070108157f000101010308040e070108157f00010101040e070108157f00010101040e07010815
2017.12.21 06:55:16 5: FRM:<f06a7f7f7f7f7f7f7f7f7f7f7f7f7f7f0001020304050607f7f06c7f7f00010101040e07010815091c7f000101010308040e07
2017.12.21 06:55:16 5: FRM:<00610062006c0065004600690072006d006100740061002e0069006e006f00f7f079020643006f006e0066006900670075007200610062006c0065004600690072006d006100740061002e0069006e006f00f7
2017.12.21 06:55:16 5: SW: f06bf7
2017.12.21 06:55:16 5: FRM:>f06bf7
2017.12.21 06:55:16 5: SW: f069f7
2017.12.21 06:55:16 5: FRM:>f069f7
2017.12.21 06:55:16 3: Firmata Firmware Version: ConfigurableFirmata.ino V_2_06
2017.12.21 06:55:16 5: FRM:<690072006d006100740061002e0069006e006f00f7e06203e11703e26002e33a02e42602e57b07e67405e73f04f079020643006f006e00660069006700750072
2017.12.21 06:55:16 5: FRM:<f90206f079020643006f006e0066006900670075007200610062006c0065004600
2017.12.21 06:55:15 5: SW: f079f7
2017.12.21 06:55:15 5: FRM:>f079f7
2017.12.21 06:55:15 3: querying Firmata Firmware Version
2017.12.21 06:55:14 5: SW: f079f7
2017.12.21 06:55:14 5: FRM:>f079f7
2017.12.21 06:55:14 3: querying Firmata Firmware Version
2017.12.21 06:55:12 5: SW: ff
2017.12.21 06:55:12 5: FRM:>ff
2017.12.21 06:54:12 3: no response from Firmata, closing DevIO
2017.12.21 06:54:12 5: SW: f079f7
2017.12.21 06:54:12 5: FRM:>f079f7
2017.12.21 06:54:12 3: querying Firmata Firmware Version
2017.12.21 06:54:11 5: SW: f079f7
2017.12.21 06:54:11 5: FRM:>f079f7
2017.12.21 06:54:11 3: querying Firmata Firmware Version
2017.12.21 06:54:10 5: SW: f079f7
2017.12.21 06:54:10 5: FRM:>f079f7
2017.12.21 06:54:10 3: querying Firmata Firmware Version
2017.12.21 06:54:09 5: SW: f079f7
2017.12.21 06:54:09 5: FRM:>f079f7
2017.12.21 06:54:09 3: querying Firmata Firmware Version
2017.12.21 06:54:07 1: fhem_hw:2004 disconnected, waiting to reappear (OWArduino)
2017.12.21 06:54:07 5: SW: ff
2017.12.21 06:54:07 5: FRM:>ff
2017.12.21 06:54:06 1: fhem_hw:2004 disconnected, waiting to reappear (OWArduino)

LG Thomas

ThoTo · 26 Dezember 2017, 16:31:07

So, ich habe jetzt die Zeile 784 mit die(...) in der Funktion onewire_command_series auskommentiert:

FHEM/lib/Device/Firmata/Platform.pm

Code Auswählen

sub onewire_command_series {
  my ( $self, $pin, $args ) = @_;
  die "pin '".$pin."' is not configured for mode 'ONEWIRE'" unless $self->is_configured_mode($pin,PIN_ONEWIRE);
  return $self->{io}->data_write($self->{protocol}->packet_onewire_request( $pin, $args ));
}

Damit stürzt FHEM nicht mehr ab, stattdessen kommt es zu folgenden Logeinträgen und das OWX Device ist auf "disconnected".

Code Auswählen

2017.12.25 20:37:28 1: OWXTHERM_BinValues:  OWX_28_FFCBE6221703: invalid data length, 0 instead of 9 bytes,  0  
2017.12.25 20:37:28 1: OWTHERM: OWX_28_FFCBE6221703 has returned invalid data of length 10
2017.12.25 20:37:23 1: OWXTHERM_BinValues:  OWX_28_FF1DE5221703: invalid data length, 0 instead of 9 bytes,  0  
2017.12.25 20:37:23 1: OWTHERM: OWX_28_FF1DE5221703 has returned invalid data of length 10

Code Auswählen

2017.12.23 10:08:00 1: OWX_FRM::Ready function called for bus OneWireBus. STATE=disconnected
2017.12.23 10:07:20 1: OWX_Complex called while interface OneWireBus disconnected
2017.12.23 10:07:16 1: OWX_Complex called while interface OneWireBus disconnected
2017.12.23 10:07:00 3: OWX_Set OneWireBus reopen => 0
2017.12.23 10:07:00 1: ====> REOPENING DEVICE
2017.12.23 09:42:24 1: OWXTHERM_BinValues:  OWX_28_FFCBE6221703: invalid data length, 0 instead of 9 bytes,  0  
2017.12.23 09:42:24 1: OWTHERM: OWX_28_FFCBE6221703 has returned invalid data of length 10
2017.12.23 09:42:20 1: OWXTHERM_BinValues:  OWX_28_FF1DE5221703: invalid data length, 0 instead of 9 bytes,  0  
2017.12.23 09:42:20 1: PERL WARNING: Use of uninitialized value $data[3] in ord at ./FHEM/21_OWTHERM.pm line 952.
2017.12.23 09:42:20 1: PERL WARNING: Use of uninitialized value $data[2] in ord at ./FHEM/21_OWTHERM.pm line 951.
2017.12.23 09:42:20 1: PERL WARNING: Use of uninitialized value $data[1] in ord at ./FHEM/21_OWTHERM.pm line 939.
2017.12.23 09:42:20 1: PERL WARNING: Use of uninitialized value $data[1] in ord at ./FHEM/21_OWTHERM.pm line 938.
2017.12.23 09:42:20 1: PERL WARNING: Use of uninitialized value $data[0] in ord at ./FHEM/21_OWTHERM.pm line 937.
2017.12.23 09:42:20 1: OWTHERM: OWX_28_FF1DE5221703 has returned invalid data of length 10
2017.12.23 09:40:22 2: CUL_TCM97001 Unknown device Unknown, please define it
2017.12.23 09:38:23 1: fhem_hw:2004 reappeared (OWArduino)
2017.12.23 09:38:23 3: Firmata Firmware Version: ConfigurableFirmata.ino V_2_06
2017.12.23 09:38:22 3: querying Firmata Firmware Version
2017.12.23 09:38:21 3: querying Firmata Firmware Version
2017.12.23 09:38:18 1: fhem_hw:2004 disconnected, waiting to reappear (OWArduino)

Wenn ich dann das define des OWX-Devices auf zB Pin 18 und wieder zurück auf Pin 19 ändere, ein reopen mache, funktioniert wieder alles.

Code Auswählen

2017.12.23 20:37:37 1: OWX: 1-Wire bus OneWireBus: interface Firmata detected in OWArduino
2017.12.23 20:37:04 1: OWX: 1-Wire bus OneWireBus: interface Firmata detected in OWArduino
2017.12.23 20:36:37 1: Error: >OWArduino:19< has no TYPE, but following keys: ><
2017.12.23 20:36:04 1: Error: >OWArduino:18< has no TYPE, but following keys: ><

Hier noch ein list des OWX-Devices im funktionierenden Zustand:

Code Auswählen

Internals:
   ALARMED    2
   ASYNCHRONOUS 0
   CFGFN      
   DEF        OWArduino:19
   DeviceName OWArduino:19
   FRM_OWX_CORRELATIONID 444
   FRM_OWX_CURRDEV 28.FFCBE6221703.E1
   HWDEVICE   OWArduino
   INITDONE   1
   INTERFACE  firmata
   IODev      OWArduino
   NAME       OneWireBus
   NEXT_OPEN  1514235363.50745
   NR         226
   PARTIAL    
   PIN        19
   PRESENT    1
   ROM_ID     FF
   STATE      Initialized
   TYPE       OWX
   interval   300
   timeout    2
   version    7.05
   DEVHASH:
     OWX_28_FF1DE5221703 28.FF1DE5221703.AB
     OWX_28_FFCBE6221703 28.FFCBE6221703.E1
     OneWireBus Busmaster
   DEVS:
     28.FF1DE5221703.AB
     28.FFCBE6221703.E1
   FRM_OWX_REPLIES:
     28.FF1DE5221703.AB �KF���
     28.FFCBE6221703.E1 �KF����
   FRM_OWX_REQUESTS:
	 ...
   READINGS:
     2017-12-21 20:26:54   queue           0
     2017-12-25 20:40:46   state           disconnected
Attributes:
   asynchronous 0
   verbose    0

Ich verschiebe das Thema nun nach 1Wire, vielleicht kommen dann noch Ideen

LG Thomas

JensS · 26 Dezember 2017, 18:59:51

Hallo Thomas,

probier mal die 10_FRM.pm: https://forum.fhem.de/index.php/topic,80409.msg724359.html#msg724359

Gruß Jens

ThoTo · 28 Dezember 2017, 16:42:57

Zitat von: dirigent am 26 Dezember 2017, 18:59:51
Hallo Thomas,

probier mal die 10_FRM.pm: https://forum.fhem.de/index.php/topic,80409.msg724359.html#msg724359

Gruß Jens

Danke, Jens!
Habe ich eingebaut, werde nun weiter beobachten und berichten.

LG Thomas

ThoTo · 29 Dezember 2017, 10:28:58

Zitat von: dirigent am 26 Dezember 2017, 18:59:51
probier mal die 10_FRM.pm: https://forum.fhem.de/index.php/topic,80409.msg724359.html#msg724359

Leider ohne Ergebnis, FHEM ist heute Nacht wieder mit "pin '19' is not configured for mode 'ONEWIRE' at FHEM/lib/Device/Firmata/Platform.pm line 784." stehengeblieben.
Das Auskommentieren der die()-Funktionen habe ich zuvor wieder rückgängig gemacht.

LG THomas

JensS · 29 Dezember 2017, 10:41:11

Hallo Thomas,

poste mal die Ausgabe von "list OWArduino".

Gruß Jens

ThoTo · 29 Dezember 2017, 11:24:50

list OWArduino

Code Auswählen

Internals:
   CFGFN      
   DEF        fhem_hw:2004
   DeviceName fhem_hw:2004
   FD         71
   NAME       OWArduino
   NOTIFYDEV  global
   NR         219
   NTFY_ORDER 50-OWArduino
   PARTIAL    
   STATE      Initialized
   TYPE       FRM
   analog_pins 14,15,16,17,18,19,20,21
   analog_resolutions 14:10,15:10,16:10,17:10,18:10,19:10,20:10,21:10
   encoder_pins 2,3
   encoder_resolutions 2:28,3:28
   firmware   ConfigurableFirmata.ino
   firmware_version V_2_06
   i2c_pins   18,19
   input_pins 2,3,4,5,6,7,8,9,10,11,12,13,14,15,16,17,18,19
   onewire_pins 2,3,4,5,6,7,8,9,10,11,12,13,14,15,16,17,18,19
   output_pins 2,3,4,5,6,7,8,9,10,11,12,13,14,15,16,17,18,19
   pwm_pins   3,5,6,9,10,11
   pwm_resolutions 3:8,5:8,6:8,9:8,10:8,11:8
   servo_pins 2,3,4,5,6,7,8,9,10,11,12,13
   servo_resolutions 2:14,3:14,4:14,5:14,6:14,7:14,8:14,9:14,10:14,11:14,12:14,13:14
   stepper_pins 2,3,4,5,6,7,8,9,10,11,12,13,14,15,16,17,18,19
   stepper_resolutions 2:21,3:21,4:21,5:21,6:21,7:21,8:21,9:21,10:21,11:21,12:21,13:21,14:21,15:21,16:21,17:21,18:21,19:21
   READINGS:
     2017-12-29 08:10:18   state           opened
Attributes:
   group      USB Dongle
   room       System
   verbose    0

LG Thomas

JensS · 29 Dezember 2017, 18:43:07

$:-\$ Vielleicht hat noch jemand anderes eine Idee dazu...
Hast du schon mal probiert, den Arduino direkt über /dev/serial/by-id/... anzusprechen?

Gruß Jens

jensb · 01 Januar 2018, 23:19:26

@ThoTo

Habe heute eine Anpassung von FRM für OWX vorbereitet. Beim Testen ist mir FHEM auch mehrfach abgestürzt. Das liegt u.a. am Modul OWX_FRM, das bei bestimmten Fehlern keine erweiterte Fehlerbehandlung macht. Anbei eine inoffizielle Version zum Testen - Maintainer von 11_OWX_FRM.pm ist @pahenning.

Die neue Version von FRM zum Testen findet man hier (das FRM-Modul allein reicht nicht für Test, bitte den ganzen Thread durchlesen).

Selbst wenn die beiden Updates zusammen die Ursache nicht beheben, dürft dein FHEM danach nicht mehr aus diesem Grund abstürzen.

Grüße,
Jens

UPDATE 07.01.2018: 11_OWX_FRM.pm aktualisiert

ThoTo · 01 Januar 2018, 23:47:41

Zitat von: jensb am 01 Januar 2018, 23:19:26

Die neue Version von FRM zum Testen findet man hier (das FRM-Modul allein reicht nicht für Test, bitte den ganzen Thread durchlesen).

Dankeschön, Jens! Habe den Thread verfolgt, komme aber erst morgen dazu die geänderten Files einzubauen.
Feedback folgt.

LG Thomas

rino · 08 Januar 2018, 20:47:30

Moin habe die FRM Version getestet.
Bei mir stürzt Fhem jedenfalls nicht mehr ab.
Mein Temperatur Sensoren liefen zu Anfang.
Dann kam es aber zu einem Disconnect meines Arduino Nano an welchem die ds18b20 hängen.
Der Nano läuft mir V2.10 der Firmata.

Hier ein Log Ausschnitt:

Code Auswählen


2018.01.08 02:12:55 1: OWX_FRM::Complex receiving inside loop no. 0 0x30 0x30 0x30 0x30 0x30 0x30 0x30 0x30 0x30 0xbe 0xfe 0x01 0x55 0x00 0x7f 0xff 0xff 0xff 0x32 
2018.01.08 02:12:55 1: OWX_FRM::Complex receiving outside loop 0x30 0x30 0x30 0x30 0x30 0x30 0x30 0x30 0x30 0x44 
2018.01.08 02:12:56 1: OWX_FRM::Complex receiving inside loop no. 0 0x30 0x30 0x30 0x30 0x30 0x30 0x30 0x30 0x30 0xbe 0x16 0x02 0x55 0x00 0x7f 0xff 0xff 0xff 0x2c 
2018.01.08 02:16:51 1: /dev/ttyUSB0 disconnected, waiting to reappear (ArduinoHWR)
2018.01.08 02:16:53 3: Setting ArduinoHWR serial parameters to 57600,8,N,1
2018.01.08 02:16:53 1: /dev/ttyUSB0 reappeared (ArduinoHWR)
2018.01.08 02:16:56 3: ArduinoHWR querying Firmata versions
2018.01.08 02:16:57 3: ArduinoHWR Firmata Firmware Version: hwr.ino V_2_10 (using Protocol Version: V_2_06)

Danach keine aktuellen Temperaturen Daten mehr.

Gruß

Reiner Emkes

JensS · 08 Januar 2018, 22:01:27

Hallo Reiner,

sichere mal die fhem.save zur späteren Analyse und lösche dann sämtliche Readings vom ArduinoHWR, dem OWX und dem DS18b20 mit deletereading ArduinoHWR .* etc.. Anschließend mit save alles sichern und shutdown restart. Ich hatte das gleiche Problem und konnte es so lösen.

Gruß Jens

ThoTo · 08 Januar 2018, 22:42:22

Ich glaube ja mittlerweile dass der Arduino neu startet.
Müsste mir mal meine Configurable Firmata Config ansehen und evt. optimieren.

LG Thomas

rino · 08 Januar 2018, 22:53:57

Hallo Jens,
Vielen Dank, hat geklappt.
Jetzt kommen wieder Temperatur Werte.
Ich melde mich morgen, ob es noch läuft.
Gruß
Reiner