[gelöst] Fehler in fhem.pl (oder Perl?) unter Windows UND Verwendung von 37_harmony

fhem_olsi · 30 April 2023, 15:10:12

Ich betreibe FHEM unter Windows. Wenn ich ein Harmony-Hub definiere, tritt ein seltsamer Fehler auf, aber auch nur dann! Ohne Harmony-Hub (entweder disabled oder gelöscht) wird kein Fehler gemeldet.
Dieser Fehler tritt auch bei einer minimalen Konfiguration auf, bei der nur ein Device definiert ist, nämlich der Harmony-Hub. Hier folgt ein Beispiel für diese minimale Konfiguration:
Windows-fhem.cfg

Code Auswählen

attr global userattr cmdIcon devStateIcon:textField-long devStateStyle icon sortby webCmd webCmdLabel:textField-long widgetOverride
attr global autoload_undefined_devices 1
attr global logfile ./log/fhem-%Y-%m.log
attr global modpath .
attr global motd none
attr global mseclog 1
attr global nofork 1
attr global room System
attr global sendStatistics never
attr global statefile ./log/fhem.save
attr global verbose 3

define telnet telnet 7072 global
setuuid telnet 64492b8e-f33f-8d39-e6ea-8f2d7ffd223b590b

define WEB FHEMWEB 8083 global
setuuid WEB 5c8aad22-f33f-c296-41f4-900a80ef379174b0
attr WEB JavaScripts codemirror/fhem_codemirror.js
attr WEB confirmDelete 0
attr WEB defaultRoom Light
attr WEB iconPath openautomation:fhemSVG:default
attr WEB room System
attr WEB sortRooms Light Cinema Residents Sensors System

# Fake FileLog entry, to access the fhem log from FHEMWEB
define Logfile FileLog ./log/fhem-%Y-%m.log fakelog
setuuid Logfile 5c8aad22-f33f-c296-8c0d-98c5ff8e9ecf00af
attr Logfile room System

define autocreate autocreate
setuuid autocreate 5c8aad22-f33f-c296-ccc7-ab49c267da2ab3bf
attr autocreate room System
define eventTypes eventTypes demolog/eventTypes.txt
setuuid eventTypes 5c8aad22-f33f-c296-9b03-59d0aff3ff49d9e6
attr eventTypes room System

define HHub harmony 192.168.0.120 remoteId=xxxxxxx
setuuid HHub 64492ffb-f33f-8d39-61a8-702f4106e93d5f65
attr HHub room Unsorted

Nach dem Start werden im Log-File folgende Meldungen ausgegeben:

Code Auswählen

2023.04.26 17:35:57.202 1: starting in console mode
2023.04.26 17:35:57.202 1: Including fhem.cfg
Der Befehl "[" ist entweder falsch geschrieben oder
konnte nicht gefunden werden.
 port 8083 opened
2023.04.26 17:35:57.518 2: eventTypes: loaded 109 lines from demolog/eventTypes.txt
2023.04.26 17:35:57.566 1: Including ./log/fhem.save
2023.04.26 17:35:57.591 3: HHub: connected
2023.04.26 17:35:57.591 1: PERL WARNING: Use of uninitialized value in pattern match (m//) at ./FHEM/37_harmony.pm line 1765.
2023.04.26 17:35:57.592 0: Featurelevel: 6.2
2023.04.26 17:35:57.592 0: Server started with 7 defined entities (fhem.pl:27055/2023-01-14 perl:5.032001 os:MSWin32 user:W7 pid:2908)
2023.04.26 17:35:57.625 3: HHub: websocket: Switching Protocols ok
2023.04.26 17:35:58.727 3: HHub: new config
2023.04.26 17:36:00.042 3: HHub: new config
2023.04.26 17:36:27.233 1: PERL WARNING: Terminating on signal SIGINT(2)#### code ####

Es wird die Fehlermeldung 'Der Befehl "[" ist entweder falsch geschrieben oder
konnte nicht gefunden werden.' ausgegeben.

Interessant dabei ist auch, daß die darauf folgenden Meldungen, die normalerweise im fehlerfreien Fall ausgegeben werden, fehlen bzw. verstümmelt sind. Es sind dies (mindestens) die Zeilen:

Code Auswählen

2023.04.25 15:51:43 3: telnet_fhem: port 7072 opened
2023.04.25 15:51:43 3: WEB: port 8083 opened

Die "telnet"-Meldung fehlt vollständig, und die "WEB"-Meldung ist verstümmelt!

Nichtsdestoweniger funktioniert der Harmony-Hub ansonsten einwandfrei.
Übrigens hift das Setzen von "stacktrace = 1" und "verbose = 5" auch nicht weiter.

Wenn ich das ganze unter Linux versuche, dann gibt es dieses Problem nicht:
Linux-fhem.cfg

Code Auswählen

attr global userattr cmdIcon devStateIcon:textField-long devStateStyle icon sortby webCmd webCmdLabel:textField-long widgetOverride
attr global autoload_undefined_devices 1
attr global logfile ./log/fhem-%Y-%m.log
attr global modpath .
attr global statefile ./log/fhem.save
attr global verbose 3

define WEB FHEMWEB 8083 global
setuuid WEB 644aa712-f33f-b647-39e7-7eb256d63e8f0a46
attr WEB editConfig 1

# Fake FileLog entry, to access the fhem log from FHEMWEB
define Logfile FileLog ./log/fhem-%Y-%m.log Logfile
setuuid Logfile 644aa712-f33f-b647-dbaa-6545daad07b8ea59

define autocreate autocreate
setuuid autocreate 644aa712-f33f-b647-b4da-ee82a9dcdff1ea50
attr autocreate filelog ./log/%NAME-%Y.log

define eventTypes eventTypes ./log/eventTypes.txt
setuuid eventTypes 644aa712-f33f-b647-97ec-39e3d34dcc1aa581

# Disable this to avoid looking for new USB devices on startup
#define initialUsbCheck notify global:INITIALIZED usb create
#setuuid initialUsbCheck 644aa712-f33f-b647-59ea-fb39b7171f0bce27

define HHub harmony 192.168.0.120 remoteId=xxxxxxx
setuuid HHub 644aafdc-f33f-b647-5cf8-cd74a7661256f986

Linux-Log-File

Code Auswählen

2023.04.27 19:27:23 1: Including fhem.cfg
2023.04.27 19:27:25 3: WEB: port 8083 opened
2023.04.27 19:27:25 2: eventTypes: loaded 6 lines from ./log/eventTypes.txt
2023.04.27 19:27:25 1: Including ./log/fhem.save
2023.04.27 19:27:25 1: Messages collected while initializing FHEM:SecurityCheck:
  WEB is not password protected

Protect this FHEM installation by defining an allowed device with define allowed allowed
You can disable this message with attr global motd none

2023.04.27 19:27:25 3: HHub: connected
2023.04.27 19:27:25 1: PERL WARNING: Use of uninitialized value in pattern match (m//) at ./FHEM/37_harmony.pm line 1765.
2023.04.27 19:27:25 0: Featurelevel: 6.2
2023.04.27 19:27:25 0: Server started with 6 defined entities (fhem.pl:27055/2023-01-14 perl:5.034000 os:linux user:fhem pid:950)
2023.04.27 19:27:25 3: HHub: websocket: Switching Protocols ok
2023.04.27 19:27:27 3: HHub: new config 
2023.04.27 19:27:28 3: HHub: new config

Ich habe einmal versucht, (mit meinen bescheidenen Perl-Kenntnissen) den Ursprung der Fehlermeldung aufzuspüren.

1)
Mein erster Ansatzpunkt war, den Bruchteil "entweder falsch geschrieben" der Fehlermeldung in irgendeiner FHEM- oder Perl-Datei aufzufinden (Ich benutze übrigens "strawberry-perl-5.32.1.1-64bit-portable"). Dieser Versuch war leider nicht erfolgreich; in keiner Datei war der Text der Fehlermeldung aufzufinden. Entweder ist dieser nur codiert vorhanden oder stammt von "außerhalb" des FHEM-Verzeichnisses, also aus irgendeiner Windows-Library etc.

2)
Dann habe ich versucht, den Ursprung der Meldung im Modul "fhem.pl" einzukreisen. Dieser muß in der Funktion "AnalyzeCommandChain" (Zeilen 1098ff) zu finden sein. Der Fehler tritt auf, wenn der zweite Aufruf-Parameter von AnalyzeCommandChain (intern also: $cmd) der folgende ist:

Code Auswählen

attr global logfile ./log/fhem-%Y-%m.log, param: global logfile ./log/fhem-%Y-%m.log

aber wie gesagt: NUR WENN das Modul 37_harmony.pl aktiv sein soll.
Näher eingekreist, tritt der Fehler in der Schleife der Zeilen 1124 - 1129 auf:

Code Auswählen

1124    while(defined($subcmd = shift @cmdList)) {
1125        $subcmd =~ s/SeMiCoLoN/;/g;
1126        $evalSpecials = $localEvalSpecials;
1127        my $lret = AnalyzeCommand($c, $subcmd, "ACC");
1128        push(@ret, $lret) if(defined($lret));
1129    }

Die Funktion "AnalyzeCommand" (Zeilen 1184 bis 1222) wird noch problemlos (?) durchlaufen; jedenfalls wird AnalyzeCommand in Zeile 1222 mit "return undef if(!$fn);" verlassen.
Dann aber - nach Rückkehr - muß irgendetwas passieren: Die Zeilen 1128 - 1129 werden nicht ausgeführt, oder etwas passiert beim push-Befehl.
Die Zeilen danach, also ab Z. 1130 werden wieder korrekt ausgeführt.

Für mich ist das etwas rätselhaft; mit meinen rudimentären Perl-Kenntnissen komme ich hier nicht weiter. Ich hoffe jetzt auf den geschulten Blick der Koryphäen hier...

Gruß, Wolfgang.

JoWiemann · 30 April 2023, 20:40:54

Hallo,
hier: https://forum.fhem.de/index.php?topic=49902.0 gab es schon mal eine Diskussion zu Deiner Fehlermeldung.

Und hier gab es leider keine Lösung: https://forum.fhem.de/index.php?topic=47724.0

Grüße Jörg

betateilchen · 30 April 2023, 20:57:14

Mit FHEM (fhem.pl, fhem.cfg oder ähnlichem) hat das nichts ursächlich zu tun.

Die Meldung

Code Auswählen

Der Befehl "[" (oder bla bli blub...) ist entweder falsch geschrieben oder konnte nicht gefunden werden.
stammt doch eindeutig aus Windows. Habt Ihr noch nie auf der cmd-Ebene in Windows einen Befehl falsch geschrieben?

Vermutlich wird in irgendeinem device ein system() Kommando ausgeführt, das auf der Systemkonsole von Windows zu einem Fehler führt und dieser Fehler wird im FHEM Log protokolliert. Alternativ kann auch irgendein perl-Modul unterhalb von FHEM ein Kommunikationsproblem mit Windows als Betriebssystem haben.

Das erklärt sowohl, warum der Fehler in FHEM ohne Timestamp geloggt wird als auch, warum das Problem unter Linux nicht auftritt.

JoWiemann · 30 April 2023, 21:12:35

Hallo betateilchen,

ok, da waren meine Scheuklappen bis vor die Augen geklappt.

Somit wäre diese Sub in 37_harmony.pm:

Code Auswählen

my $harmony_isFritzBox = undef;
sub
harmony_isFritzBox()
{
  $harmony_isFritzBox = int( qx( [ -f /usr/bin/ctlmgr_ctl ] && echo 1 || echo 0 ) )  if( !defined($harmony_isFritzBox) );

  return $harmony_isFritzBox;
}

für mich der Auslöser.

ungetesteter Änderungsvorschlag:

Code Auswählen


my $harmony_isFritzBox = 0;
sub
harmony_isFritzBox()
{
  # $harmony_isFritzBox = int( qx( [ -f /usr/bin/ctlmgr_ctl ] && echo 1 || echo 0 ) )  if( !defined($harmony_isFritzBox) );

  return $harmony_isFritzBox;
}

Grüße Jörg

fhem_olsi · 01 Mai 2023, 11:19:42

@JoWiemann:
Volltreffer!

Zitatfür mich der Auslöser.
ungetesteter Änderungsvorschlag:

Code Auswählen

# $harmony_isFritzBox = int( qx( [ -f /usr/bin/ctlmgr_ctl ] && echo 1 || echo 0 ) )  if( !defined($harmony_isFritzBox) );

Hat funktioniert; der Fehler ist weg, demzufolge auch die Fehlermeldung.
Danke.

@betateilchen:

ZitatVermutlich wird in irgendeinem device ein system() Kommando ausgeführt, das auf der Systemkonsole von Windows zu einem Fehler führt und dieser Fehler wird im FHEM Log protokolliert.

Genauso war es: "qx( [..."
Danke.

Gruß, Wolfgang

JoWiemann · 01 Mai 2023, 19:33:20

Zitat von: fhem_olsi am 01 Mai 2023, 11:19:42Hat funktioniert; der Fehler ist weg, demzufolge auch die Fehlermeldung.
Danke.

Hallo Wolfgang,

hast Du diese Änderung:

my $harmony_isFritzBox = undef;

nach

my $harmony_isFritzBox = 0;

auch umgesetzt. Wenn nicht, dann glaubt das Modul Fhem läuft auf einer FritzBox. Und da weiß ich nicht was das für Nebenwirkungen hat.

Grüße Jörg

fhem_olsi · 02 Mai 2023, 10:58:28

Hi Jörg,

hatte ich tatsächlich übersehen!
Danke für den Hinweis.

ZitatWenn nicht, dann glaubt das Modul Fhem läuft auf einer FritzBox.
Und da weiß ich nicht was das für Nebenwirkungen hat.

Ich denke nicht, denn "$harmony_isFritzBox = undef;" hat dieselbe Auswirkung wie "$harmony_isFritzBox = 0;", oder nicht?
Und der Aufruf der Sub kommt genau zweimal vor:

Code Auswählen

	Line   33:   return eval { decode_json($data) } if( harmony_isFritzBox() );
	Line  259:   #$attr{$name}{nossl} = 1 if( !$init_done && harmony_isFritzBox() );

Dennoch hast Du recht, "$harmony_isFritzBox = 0;" ist "irgendwie sauberer"...

Gruß, Wolfgang.