OWX Next Generation

UweH · 19 Mai 2017, 17:37:59

Ich habe die 7.0beta1 heute auf meinen Live-Server draufgepackt. Ich habe erst mal synchron getestet, habe jetzt umgestellt. Mal sehen, was so passiert...
Und als Erstes sind mir die genannten Logeinträge aufgefallen.

Die Verbindung zu den Interfaces ist aber nicht unterbrochen...alle Busse sind da.

Gruß
Uwe

Prof. Dr. Peter Henning · 19 Mai 2017, 17:51:10

Und die readings sind ok ?

LG

pah

UweH · 19 Mai 2017, 17:58:40

Ja, readings sind ok, ich habe keine "fühlbaren" Abbrüche, ich sehe das nur am Log.
Aber eben habe ich gesehen, dass es seit der Umstellung auf Asynchron keine derartigen Einträge mehr gibt. Guck an.

Gruß
Uwe

Starkstrombastler · 19 Mai 2017, 22:34:22

Hallo,

ich habe heute die Module aus dem Post vom 14.02.2017 in mein System eingespielt. Fhem startet und zeigt für die beiden Busse version=6.4alpha6.

Die Busse gehen aber erst nach mehreren set..reopen in den Status OPENED, aber leider nicht besonders lange, dann kommt der Status DISCONNECTED.

Code Auswählen

2017.05.19 22:23:21.053 1: OWXSWITCH_BinValues called for device swHeizung in context ds2408.getstate.final with data 0xff 0xff 0x09 0x00 0x00 0x88 0xff 0xff 0xbb 0xf6 
2017.05.19 22:23:21.053 1: OWXSWITCH_BinValues: swHeizung: no error, 0xff 0xff 0x09 0x00 0x00 0x88 0xff 0xff 0xbb 0xf6 
2017.05.19 22:23:23.240 1: OWX_SER::Query OWusb2: Sending out0xe3 0xc5 
2017.05.19 22:23:23.240 5: SW: e3c5
2017.05.19 22:23:23.285 4: OWX_SER::Query OWusb2: 1 of 1 bytes in first attempt and state opened
2017.05.19 22:23:23.285 1: OWX_SER::Complex sending 0x55 0x29 0x47 0x98 0x0c 0x00 0x00 0x00 0x48 0xf0 0x88 0x00 0xff 0xff 0xff 0xff 0xff 0xff 0xff 0xff 0xff 0xff 
2017.05.19 22:23:23.286 1: OWX_SER::Query OWusb2: Sending out0xe1 0x55 0x29 0x47 0x98 0x0c 0x00 0x00 0x00 0x48 0xf0 0x88 0x00 0xff 0xff 0xff 0xff 0xff 0xff 0xff 0xff 0xff 0xff 
2017.05.19 22:23:23.286 5: SW: e1552947980c00000048f08800ffffffffffffffffffff
2017.05.19 22:23:23.327 4: OWX_SER::Query OWusb2: 22 of 22 bytes in first attempt and state opened
2017.05.19 22:23:23.327 1: OWX_SER::Complex receiving 0x55 0x29 0x47 0x98 0x0c 0x00 0x00 0x00 0x48 0xf0 0x88 0x00 0xfd 0xfd 0xfe 0x00 0x00 0x88 0xff 0xff 0x0c 0xa8 
2017.05.19 22:23:23.327 1: OWXSWITCH_BinValues called for device swGartenlicht in context ds2408.getstate.final with data 0xfd 0xfd 0xfe 0x00 0x00 0x88 0xff 0xff 0x0c 0xa8 
2017.05.19 22:23:23.327 1: OWXSWITCH_BinValues: swGartenlicht: no error, 0xfd 0xfd 0xfe 0x00 0x00 0x88 0xff 0xff 0x0c 0xa8 
2017.05.19 22:23:23.788 1: /dev/serial/by-id/usb-FTDI_FT232R_USB_UART_A602PGQJ-if00-port0 disconnected, waiting to reappear (OWusb)
2017.05.19 22:23:24.648 1: 1-Wire Interface: OWusb DISCONNECTED
2017.05.19 22:23:24.662 1: PERL WARNING: Use of uninitialized value $sb in concatenation (.) or string at ./FHEM/11_OWX_SER.pm line 497.
2017.05.19 22:23:24.662 1: stacktrace:
2017.05.19 22:23:24.662 1:     main::__ANON__                      called by ./FHEM/11_OWX_SER.pm (497)
2017.05.19 22:23:24.662 1:     OWX_SER::Query                      called by ./FHEM/11_OWX_SER.pm (252)
2017.05.19 22:23:24.662 1:     OWX_SER::Complex                    called by ./FHEM/00_OWX.pm (1190)
2017.05.19 22:23:24.662 1:     main::OWX_Complex                   called by ./FHEM/21_OWCOUNT.pm (1768)
2017.05.19 22:23:24.662 1:     main::OWXCOUNT_GetPage              called by ./FHEM/21_OWCOUNT.pm (930)
2017.05.19 22:23:24.663 1:     main::OWCOUNT_GetPage               called by ./FHEM/21_OWCOUNT.pm (1182)
2017.05.19 22:23:24.663 1:     main::OWCOUNT_GetValues             called by fhem.pl (2990)
2017.05.19 22:23:24.663 1:     main::HandleTimeout                 called by fhem.pl (617)
2017.05.19 22:23:24.673 1: PERL WARNING: Use of uninitialized value $sb in concatenation (.) or string at ./FHEM/11_OWX_SER.pm line 497.
2017.05.19 22:23:24.673 1: stacktrace:
2017.05.19 22:23:24.673 1:     main::__ANON__                      called by ./FHEM/11_OWX_SER.pm (497)
2017.05.19 22:23:24.673 1:     OWX_SER::Query                      called by ./FHEM/11_OWX_SER.pm (252)
2017.05.19 22:23:24.673 1:     OWX_SER::Complex                    called by ./FHEM/00_OWX.pm (1190)
2017.05.19 22:23:24.673 1:     main::OWX_Complex                   called by ./FHEM/21_OWCOUNT.pm (1768)
2017.05.19 22:23:24.673 1:     main::OWXCOUNT_GetPage              called by ./FHEM/21_OWCOUNT.pm (930)
2017.05.19 22:23:24.673 1:     main::OWCOUNT_GetPage               called by ./FHEM/21_OWCOUNT.pm (1182)
2017.05.19 22:23:24.673 1:     main::OWCOUNT_GetValues             called by fhem.pl (2990)
2017.05.19 22:23:24.674 1:     main::HandleTimeout                 called by fhem.pl (617)
2017.05.19 22:23:24.684 1: PERL WARNING: Use of uninitialized value $sb in concatenation (.) or string at ./FHEM/11_OWX_SER.pm line 497.
2017.05.19 22:23:24.684 1: stacktrace:
2017.05.19 22:23:24.684 1:     main::__ANON__                      called by ./FHEM/11_OWX_SER.pm (497)
2017.05.19 22:23:24.684 1:     OWX_SER::Query                      called by ./FHEM/11_OWX_SER.pm (252)
2017.05.19 22:23:24.684 1:     OWX_SER::Complex                    called by ./FHEM/00_OWX.pm (1190)
2017.05.19 22:23:24.684 1:     main::OWX_Complex                   called by ./FHEM/21_OWCOUNT.pm (1768)
2017.05.19 22:23:24.684 1:     main::OWXCOUNT_GetPage              called by ./FHEM/21_OWCOUNT.pm (930)
2017.05.19 22:23:24.684 1:     main::OWCOUNT_GetPage               called by ./FHEM/21_OWCOUNT.pm (1182)
2017.05.19 22:23:24.684 1:     main::OWCOUNT_GetValues             called by fhem.pl (2990)
2017.05.19 22:23:24.685 1:     main::HandleTimeout                 called by fhem.pl (617)
2017.05.19 22:23:24.695 1: PERL WARNING: Use of uninitialized value $sb in concatenation (.) or string at ./FHEM/11_OWX_SER.pm line 497.
2017.05.19 22:23:24.695 1: stacktrace:
2017.05.19 22:23:24.695 1:     main::__ANON__                      called by ./FHEM/11_OWX_SER.pm (497)
2017.05.19 22:23:24.695 1:     OWX_SER::Query                      called by ./FHEM/11_OWX_SER.pm (252)
2017.05.19 22:23:24.695 1:     OWX_SER::Complex                    called by ./FHEM/00_OWX.pm (1190)
2017.05.19 22:23:24.695 1:     main::OWX_Complex                   called by ./FHEM/21_OWCOUNT.pm (1768)
2017.05.19 22:23:24.695 1:     main::OWXCOUNT_GetPage              called by ./FHEM/21_OWCOUNT.pm (930)
2017.05.19 22:23:24.695 1:     main::OWCOUNT_GetPage               called by ./FHEM/21_OWCOUNT.pm (1182)
2017.05.19 22:23:24.695 1:     main::OWCOUNT_GetValues             called by fhem.pl (2990)
2017.05.19 22:23:24.695 1:     main::HandleTimeout                 called by fhem.pl (617)
2017.05.19 22:23:24.706 1: PERL WARNING: Use of uninitialized value $sb in concatenation (.) or string at ./FHEM/11_OWX_SER.pm line 519.
2017.05.19 22:23:24.706 1: stacktrace:
2017.05.19 22:23:24.706 1:     main::__ANON__                      called by ./FHEM/11_OWX_SER.pm (519)
2017.05.19 22:23:24.706 1:     OWX_SER::Query                      called by ./FHEM/11_OWX_SER.pm (252)
2017.05.19 22:23:24.706 1:     OWX_SER::Complex                    called by ./FHEM/00_OWX.pm (1190)
2017.05.19 22:23:24.706 1:     main::OWX_Complex                   called by ./FHEM/21_OWCOUNT.pm (1768)
2017.05.19 22:23:24.706 1:     main::OWXCOUNT_GetPage              called by ./FHEM/21_OWCOUNT.pm (930)
2017.05.19 22:23:24.706 1:     main::OWCOUNT_GetPage               called by ./FHEM/21_OWCOUNT.pm (1182)
2017.05.19 22:23:24.706 1:     main::OWCOUNT_GetValues             called by fhem.pl (2990)
2017.05.19 22:23:24.706 1:     main::HandleTimeout                 called by fhem.pl (617)
2017.05.19 22:23:24.707 1: PERL WARNING: Use of uninitialized value $sb in concatenation (.) or string at ./FHEM/11_OWX_SER.pm line 530.
2017.05.19 22:23:24.707 1: stacktrace:
2017.05.19 22:23:24.707 1:     main::__ANON__                      called by ./FHEM/11_OWX_SER.pm (530)
2017.05.19 22:23:24.707 1:     OWX_SER::Query                      called by ./FHEM/11_OWX_SER.pm (252)
2017.05.19 22:23:24.707 1:     OWX_SER::Complex                    called by ./FHEM/00_OWX.pm (1190)
2017.05.19 22:23:24.707 1:     main::OWX_Complex                   called by ./FHEM/21_OWCOUNT.pm (1768)
2017.05.19 22:23:24.707 1:     main::OWXCOUNT_GetPage              called by ./FHEM/21_OWCOUNT.pm (930)
2017.05.19 22:23:24.707 1:     main::OWCOUNT_GetPage               called by ./FHEM/21_OWCOUNT.pm (1182)
2017.05.19 22:23:24.707 1:     main::OWCOUNT_GetValues             called by fhem.pl (2990)
2017.05.19 22:23:24.707 1:     main::HandleTimeout                 called by fhem.pl (617)
2017.05.19 22:23:24.717 1: PERL WARNING: Use of uninitialized value $sb in concatenation (.) or string at ./FHEM/11_OWX_SER.pm line 530.
2017.05.19 22:23:24.717 1: stacktrace:
2017.05.19 22:23:24.718 1:     main::__ANON__                      called by ./FHEM/11_OWX_SER.pm (530)
2017.05.19 22:23:24.718 1:     OWX_SER::Query                      called by ./FHEM/11_OWX_SER.pm (252)
2017.05.19 22:23:24.718 1:     OWX_SER::Complex                    called by ./FHEM/00_OWX.pm (1190)
2017.05.19 22:23:24.718 1:     main::OWX_Complex                   called by ./FHEM/21_OWCOUNT.pm (1768)
2017.05.19 22:23:24.718 1:     main::OWXCOUNT_GetPage              called by ./FHEM/21_OWCOUNT.pm (930)
2017.05.19 22:23:24.718 1:     main::OWCOUNT_GetPage               called by ./FHEM/21_OWCOUNT.pm (1182)
2017.05.19 22:23:24.718 1:     main::OWCOUNT_GetValues             called by fhem.pl (2990)
2017.05.19 22:23:24.718 1:     main::HandleTimeout                 called by fhem.pl (617)
2017.05.19 22:23:24.728 1: PERL WARNING: Use of uninitialized value $sb in concatenation (.) or string at ./FHEM/11_OWX_SER.pm line 530.
2017.05.19 22:23:24.728 1: stacktrace:
2017.05.19 22:23:24.728 1:     main::__ANON__                      called by ./FHEM/11_OWX_SER.pm (530)
2017.05.19 22:23:24.729 1:     OWX_SER::Query                      called by ./FHEM/11_OWX_SER.pm (252)
2017.05.19 22:23:24.729 1:     OWX_SER::Complex                    called by ./FHEM/00_OWX.pm (1190)
2017.05.19 22:23:24.729 1:     main::OWX_Complex                   called by ./FHEM/21_OWCOUNT.pm (1768)
2017.05.19 22:23:24.729 1:     main::OWXCOUNT_GetPage              called by ./FHEM/21_OWCOUNT.pm (930)
2017.05.19 22:23:24.729 1:     main::OWCOUNT_GetPage               called by ./FHEM/21_OWCOUNT.pm (1182)
2017.05.19 22:23:24.729 1:     main::OWCOUNT_GetValues             called by fhem.pl (2990)
2017.05.19 22:23:24.729 1:     main::HandleTimeout                 called by fhem.pl (617)
2017.05.19 22:23:24.739 1: PERL WARNING: Use of uninitialized value $sb in concatenation (.) or string at ./FHEM/11_OWX_SER.pm line 530.
2017.05.19 22:23:24.739 1: stacktrace:
2017.05.19 22:23:24.739 1:     main::__ANON__                      called by ./FHEM/11_OWX_SER.pm (530)
2017.05.19 22:23:24.740 1:     OWX_SER::Query                      called by ./FHEM/11_OWX_SER.pm (252)
2017.05.19 22:23:24.740 1:     OWX_SER::Complex                    called by ./FHEM/00_OWX.pm (1190)
2017.05.19 22:23:24.740 1:     main::OWX_Complex                   called by ./FHEM/21_OWCOUNT.pm (1768)
2017.05.19 22:23:24.740 1:     main::OWXCOUNT_GetPage              called by ./FHEM/21_OWCOUNT.pm (930)
2017.05.19 22:23:24.740 1:     main::OWCOUNT_GetPage               called by ./FHEM/21_OWCOUNT.pm (1182)
2017.05.19 22:23:24.740 1:     main::OWCOUNT_GetValues             called by fhem.pl (2990)
2017.05.19 22:23:24.740 1:     main::HandleTimeout                 called by fhem.pl (617)
2017.05.19 22:23:24.750 1: OWX_SER::Query OWusb:  35 of 54 bytes in last attempt and state opened, this is an unrecoverable error
2017.05.19 22:23:25.594 1: 1-Wire Interface: OWusb DISCONNECTED

Vielleicht hilft's etwas...

Viele Grüße
Starkstrombastler

UweH · 19 Mai 2017, 22:46:17

Ich habe die 7.0beta1 auch erst einmal wieder von meinem Live-System geschmissen. Nach der Umstellung auf asynchron hat es gerade mal eine halbe Stunde gedauert, bis FHEM wieder gestanden hat.
Ich glaube langsam tatsächlich, dass meine Kiste zu schnell ist. Vielleicht sollte ich doch wieder auf einen Raspberry umsteigen.

Gruß
Uwe

Prof. Dr. Peter Henning · 20 Mai 2017, 17:34:59

Na ja.

6.4alpha6 ist nun schon Monate alt, und komplett obsolet. Die aktuelle Version ist 7.0beta1.

@starkstrombastler: Ich sehe da keine relevante Fehlermeldung außer der letzten Zeile (das nicht initialisierte $sb ist trivial, das macht nichts)
Diese letzte Zeile besagt: Wir befinden uns in synchronem Betrieb, und haben nur 35 statt 54 Byte empfangen.

Das kann nur bedeuten: Das Interface ist LANGSAMER als erwartet, und man müsste noch häufiger nachfragen (oder mit größerem Delay). Oder es ist SCHNELLER als erwartet, und wir haben 19 Byte verpasst. Bitte mal mit den zuletzt geposteten Versionen probieren.

@UweH: Tja. Ich habe die neuen Versionen auf allen 6 Bussen laufen. Ab und zu mal eine Kollision - dann passiert so etwas wie heute kurz vor Mitternacht:

Code Auswählen

2017.05.19 23:55:25 1: /dev/owxug2 disconnected, waiting to reappear (OWX_UG2)
2017.05.19 23:55:25 1: PERL WARNING: Use of uninitialized value $sb in concatenation (.) or string at /opt/fhem/FHEM/11_OWX_SER.pm line 350, <OWXFILE> line 42.
2017.05.19 23:55:25 1: OWX_SER::Read OWX_UG2: -7 of 35 bytes in last attempt (first round -9) and state opened, this is an unrecoverable error
2017.05.19 23:55:25 1: PERL WARNING: Use of uninitialized value $buffer in subtraction (-) at /opt/fhem/FHEM/00_OWX.pm line 867, <OWXFILE> line 42.
2017.05.19 23:56:30 1: OWX_Discover: 1-Wire devices found on bus OWX_UG2 (BK.Alarm,BK.OWM,VK.OWM,WK.OWM,G.Verb,W.Verb)
2017.05.19 23:56:30 1: /dev/owxug2 reappeared (OWX_UG2)

Also, nach einer Minute (= nächste Leseoperation) ist das Teil wieder da.

Alles stabil, und asynchron.

Ich habe infolgedessen auch schon den hardwareabhängigen Teil für COC/CUNO umgebaut, als Nächstes ist das Firmata-Interface dran.

Und, der langen Rede kurzer Sinn: Ich kann diese Stillstände bei Dir eben wirklich nicht nachvollziehen - bei mir hat die Kiste nur dann gehangen, wenn DevIOReadWithTimeout endlos gehangen hat.

LG

pah

UweH · 21 Mai 2017, 12:27:04

Zitat von: Prof. Dr. Peter Henning am 20 Mai 2017, 17:34:59
6.4alpha6 ist nun schon Monate alt, und komplett obsolet. Die aktuelle Version ist 7.0beta1.

Bei mir sieht es aber auch so aus...Abfrage ergibt 7.0beta1, aufgeführt wird aber 6.4alpha6:

Prof. Dr. Peter Henning · 21 Mai 2017, 13:26:06

Da war noch ein falscher String drin.

Die Ursache für das Hängenbleiben von FHEM ist übrigens - das liegt an der betreffenden Read-Funktion in DevIO.pm. Ich habe da inzwischen einen ganz anderen Ansatz in eine experimentelle Version von OWX_TCP eingebaut, die das vermeiden kann. Ich hänge das mal an, bitte mit Vorsicht testen.

LG

pah

cwagner · 21 Mai 2017, 14:46:01

Ich hab's mal mit dem Set dieser neuesten Versionen versucht und bin leider wieder gescheitert. In meiner Konstellation (PI2, Denkovi USB to One Wire converter - FT232RL (USB-UART converter) and DS2480B Dallas-Maxim (RS232-One Wire converter)) wird asynchronous mit den neuen Modulen kein Device erkannt. Wohl aber zählt das Reading "Queue" munter.

Ich muss erst mal wieder zurück auf die Versionen aus dem Repository.

Christian

UweH · 21 Mai 2017, 14:52:52

Auf meiner Testmaschine läuft es erst mal...

Gruß
Uwe

Prof. Dr. Peter Henning · 21 Mai 2017, 14:53:04

@cwagner:
Logfile bei verbose=5 ?

@UweH:
Habe dazu meine eigene Timeout-Leseroutine eingebaut

LG

pah

cwagner · 21 Mai 2017, 15:20:03

OK, habe ich gemacht und wegen der Datenmenge in wenigen Minuten als Datei eingehängt.

Christian

Prof. Dr. Peter Henning · 21 Mai 2017, 16:24:56

Witzig - oder auch nicht. Die Devices werden erkannt und die Queue ordentlich aufgebaut. Auch das Aussenden geht noch, z.B.

Code Auswählen

OWX_SER::Query OWio1: 1 of 1 bytes in first attempt and state opened
2017.05.21 15:10:31 1: OWX_SER::Write Sending out 0xe1 0xcc 0xcc 0x44

oder

Code Auswählen

: OWX_SER::Query OWio1: Sending out0xe3 0xc5 
2017.05.21 15:10:33 5: SW: e3c5
2017.05.21 15:10:33 4: OWX_SER::Query OWio1: 1 of 1 bytes in first attempt and state opened
2017.05.21 15:10:33 1: OWX_SER::Write Sending out 0xe1 0x55 0x28 0x0e 0x37 0xac 0x04 0x00 0x00 0xfd 0x4e 0x4b 0x46 0x7f 0xff 0xff 0xff

Allerdings wartet sich die Queue dann tot - nur sehr selten kommen Daten an, z.B.

Code Auswählen

OWX_SER::Query OWio1: Sending out0xe3 0xc5 
2017.05.21 15:11:34 5: SW: e3c5
2017.05.21 15:11:34 4: OWX_SER::Query OWio1: 1 of 1 bytes in first attempt and state opened
2017.05.21 15:11:34 1: OWX_SER::Write Sending out 0xe1 0x55 0x28 0x90 0x5f 0x9b 0x01 0x00 0x00 0x8b 0xbe 0xff 0xff 0xff 0xff 0xff 0xff 0xff 0xff 0xff 
2017.05.21 15:11:34 5: SW: e15528905f9b0100008bbeffffffffffffffffff
2017.05.21 15:11:34 1: /dev/ttyUSB0 disconnected, waiting to reappear (OWio1)
2017.05.21 15:11:35 5: OWX_SER::Read OWio1: -4 of 9 bytes in 1st attempt try 10 and state opened
2017.05.21 15:11:35 1: OWX_SER::Read OWio1: -4 of 9 bytes - something wrong with the 1-Wire device ???
2017.05.21 15:11:35 1: OWX_Read: OWio1 received -4 instead of 9 bytes
2017.05.21 15:11:35 1: buffer is 0x55 0x28 0x90 0x5f 0x9b 0x01

Wie man hier ablesen kann, hat das Modul 10 Leseversuche unternommen und dabei 13 Byte zuwenig geholt. Das "0x55 0x28 0x90 0x5f 0x9b 0x01" ist gerade erst mal der Anfang des Readings, nämlich die ersten Adressbytes eines DS18B20.

Mit anderen Worten: Dieses Interface ist GAAANZ LANGSAM. Vlt. mal zum Auspobieren in der Routine Read() im 11_OWX_SER.pm etwas ändern:

Code Auswählen

 #-- several tries to read from slow device     
  }elsif( ($numget>-10) && ($numget<$numexp) ){                                
    for($try=0;$try<   10    ;$try++) {  
      $buffer .= main::DevIo_SimpleRead($hash);                 
      $numget  = length($buffer)-10;            
      last
        if( $numget>=$numexp );  
      select(undef,undef,undef,    0.01   );
    }

Und zwar die Anzahl der Leseversuche auf 10 -> 100, oder die Pause zwischen zwei Versuchen 0.01 -> 0.03. Ich habe beide Stellen oben durch Leerzeichen markiert

LG

pah

UweH · 21 Mai 2017, 18:12:52

Bisher läuft es gut, diese Meldungen kamen eben.

Code Auswählen

2017.05.21 18:07:20 1: PERL WARNING: substr outside of string at ./FHEM/21_OWSWITCH.pm line 1000.
2017.05.21 18:07:20 1: PERL WARNING: Use of uninitialized value $res in numeric ne (!=) at ./FHEM/21_OWSWITCH.pm line 1133.
2017.05.21 18:07:20 1: PERL WARNING: Use of uninitialized value in concatenation (.) or string at ./FHEM/21_OWSWITCH.pm line 1135.

Gruß
Uwe

Prof. Dr. Peter Henning · 21 Mai 2017, 19:10:32

Bitte mal in dem OWSWITCH Device mit "get version" die Version des OWSWITCH-Moduls abfragen.

LG

pah