fhem macht öfters und einen reboot

hermann1514 · 23 Januar 2019, 14:48:07

Hi zusammen,

was bei mir LOG aufgefallen ist, dass meine FHEM Instanz des öfteren einen Reboot macht. Auch wenn ich gerade nicht per Browser in der WEBGUI bin.

Was auffällig ist, dass folgender Eintrag immer wieder auftaucht, kurz bevor fhem neustartet...:

Code Auswählen

HTTP::Message content must be bytes at /usr/share/perl5/HTTP/Request/Common.pm line 97.
2019.01.23 14:43:27 1: Including fhem.cfg

Kennt jemand das Problem?
Danke.
Gruß
Hermann

MadMax-FHEM · 23 Januar 2019, 14:49:18

Ein (etwas) größerer (und ungekürzter!?) Logauszug wäre hilfreich...

Gruß, Joachim

hermann1514 · 23 Januar 2019, 14:56:39

Hmm....mal gucken ob es so in Ordnung ist:

Code Auswählen


2019.01.23 14:50:43 3: Stube_Harmony_Hub: new config 

HTTP::Message content must be bytes at /usr/share/perl5/HTTP/Request/Common.pm line 97.

2019.01.23 14:50:44 1: Including fhem.cfg

2019.01.23 14:50:44 3: WEB: port 8083 opened

2019.01.23 14:50:44 2: eventTypes: loaded 2217 events from ./log/eventTypes.txt

2019.01.23 14:50:44 3: EC3000_7918: I/O device is mylgw1

2019.01.23 14:50:44 3: EC3000_5B41: I/O device is mylgw1

2019.01.23 14:50:44 3: EC3000_4C6F: I/O device is mylgw1

2019.01.23 14:50:44 3: EC3000_D7C1: I/O device is mylgw1

2019.01.23 14:50:44 3: EC3000_D7AA: I/O device is mylgw1

2019.01.23 14:50:44 3: EC3000_75F1: I/O device is mylgw1

2019.01.23 14:50:44 3: EC3000_D792: I/O device is mylgw1

2019.01.23 14:50:44 3: EC3000_7898: I/O device is mylgw1

2019.01.23 14:50:44 3: RM_HmUART_EG device closed

2019.01.23 14:50:44 3: Opening RM_HmUART_EG device xxx.xx.xx.x:2000

2019.01.23 14:50:45 3: GOOGLECAST: GoogleCast v2.1.3

2019.01.23 14:50:45 3: GOOGLECAST: Stube initializing...

2019.01.23 14:50:45 3: telnetForBlockingFn_1548251445: port 36287 opened

2019.01.23 14:50:45 3: GOOGLECAST: Küche initializing...

2019.01.23 14:50:45 3: Opening ZWDongle1 device /dev/ttyACM0

2019.01.23 14:50:45 3: Setting ZWDongle1 serial parameters to 115200,8,N,1

2019.01.23 14:50:46 3: ZWDongle1 device opened

2019.01.23 14:50:46 3: ZWave: cannot load Crypt::Rijndael, SECURITY class disabled

2019.01.23 14:50:46 3: Opening SCC_CUL_MAX device xxx.xx.xx.xxx:2323

2019.01.23 14:50:46 3: SCC_CUL_MAX: Possible commands: mBbCFiAZGMYRTVWXef*ltuxz

2019.01.23 14:50:46 3: SCC_CUL_MAX device opened

2019.01.23 14:50:46 2: Switched SCC_CUL_MAX rfmode to MAX

2019.01.23 14:50:47 3: CUL_MAX_Check: Detected firmware version 154 of the CUL-compatible IODev

2019.01.23 14:50:47 3: TelegramBot_Define Telegram: called 

2019.01.23 14:50:47 2: VIERA: defined with host: xxx.xx.xx.x and interval: 30

2019.01.23 14:50:47 3: Kueche_LaCrosse_Temp: I/O device is mylgw1

2019.01.23 14:50:47 3: Spielzimmer_LaCrosse_Temp: I/O device is mylgw1

2019.01.23 14:50:47 3: Schlafzimmer_Eltern_LaCrosse_Temp: I/O device is mylgw1

2019.01.23 14:50:47 1: Including ./log/fhem.save

2019.01.23 14:50:47 3: No I/O device found for mqttGenericBridge

2019.01.23 14:50:47 3: Device Badezimmer_oben_Fenster added to ActionDetector with 002:50 time

2019.01.23 14:50:47 3: Device Badezimmer_oben_Heizung added to ActionDetector with 000:10 time

2019.01.23 14:50:47 3: Device Badezimmer_unten_Fenster added to ActionDetector with 002:50 time

2019.01.23 14:50:47 3: Device Badezimmer_unten_Heizung added to ActionDetector with 000:10 time

2019.01.23 14:50:47 3: Device Flur_oben_Bewegunsmelder added to ActionDetector with 000:20 time

2019.01.23 14:50:47 3: Device Flur_unten_Bewegungsmelder added to ActionDetector with 000:20 time

2019.01.23 14:50:48 3: Device HM_417870 added to ActionDetector with 000:10 time

2019.01.23 14:50:48 3: Device HM_417C94 added to ActionDetector with 000:10 time

2019.01.23 14:50:48 3: Device Kueche_Bewegungsmelder added to ActionDetector with 000:20 time

2019.01.23 14:50:48 3: Device Kueche_Heizung added to ActionDetector with 000:10 time

2019.01.23 14:50:48 3: Device Kueche_Terrassentuer added to ActionDetector with 002:50 time

2019.01.23 14:50:48 3: Device Schlafzimmer_Eltern_Fenster added to ActionDetector with 002:50 time

2019.01.23 14:50:48 3: Device Schlafzimmer_Eltern_Heizung added to ActionDetector with 000:10 time

2019.01.23 14:50:48 3: Device Schlafzimmer_Eltern_Stehlampe added to ActionDetector with 000:10 time

2019.01.23 14:50:48 3: Device Schlafzimmer_Leni_Fenster added to ActionDetector with 002:50 time

2019.01.23 14:50:48 3: Device Schlafzimmer_Leni_Heizung added to ActionDetector with 000:10 time

2019.01.23 14:50:48 3: Device Schlafzimmer_Luca_Heizung added to ActionDetector with 000:10 time

2019.01.23 14:50:48 3: Device Spielzimmer_Fenster added to ActionDetector with 002:50 time

2019.01.23 14:50:48 3: Device Spielzimmer_Heizung added to ActionDetector with 000:10 time

2019.01.23 14:50:48 3: Device Stube_Bewegungsmelder added to ActionDetector with 000:20 time

2019.01.23 14:50:48 3: Device Stube_Fenster_Seite added to ActionDetector with 002:50 time

2019.01.23 14:50:48 3: Device Stube_Fenster_Strasse added to ActionDetector with 002:50 time

2019.01.23 14:50:48 3: Device Stube_Heizung_Seite added to ActionDetector with 000:10 time

2019.01.23 14:50:48 3: Device Stube_Heizung_Strasse added to ActionDetector with 000:10 time

2019.01.23 14:50:48 3: Device Stube_Stehlampe added to ActionDetector with 000:10 time

2019.01.23 14:50:48 3: Device Stube_kleine_Tischlampe added to ActionDetector with 000:10 time

2019.01.23 14:50:48 3: Device Waschraum_Fenster added to ActionDetector with 002:50 time

2019.01.23 14:50:48 3: harmony: starting discovery

2019.01.23 14:50:48 3: harmony: sending discovery

2019.01.23 14:50:48 1: usb create starting

2019.01.23 14:50:48 3: Probing CUL device /dev/ttyS0

2019.01.23 14:50:48 1: PERL WARNING: can't getattr: Input/output error at FHEM/DevIo.pm line 420.

2019.01.23 14:50:48 1: CUL: Can't open /dev/ttyS0: Input/output error

2019.01.23 14:50:48 3: Probing CUL device /dev/ttyS1

2019.01.23 14:50:48 1: CUL: Can't open /dev/ttyS1: Input/output error

2019.01.23 14:50:48 3: Probing CUL device /dev/ttyS10

2019.01.23 14:50:48 1: CUL: Can't open /dev/ttyS10: Input/output error

2019.01.23 14:50:48 3: Probing CUL device /dev/ttyS11

2019.01.23 14:50:48 1: CUL: Can't open /dev/ttyS11: Input/output error

2019.01.23 14:50:48 3: Probing CUL device /dev/ttyS12

2019.01.23 14:50:48 1: CUL: Can't open /dev/ttyS12: Input/output error

2019.01.23 14:50:48 3: Probing CUL device /dev/ttyS13

2019.01.23 14:50:48 1: CUL: Can't open /dev/ttyS13: Input/output error

2019.01.23 14:50:48 3: Probing CUL device /dev/ttyS14

2019.01.23 14:50:48 1: CUL: Can't open /dev/ttyS14: Input/output error

2019.01.23 14:50:48 3: Probing CUL device /dev/ttyS15

2019.01.23 14:50:48 1: CUL: Can't open /dev/ttyS15: Input/output error

2019.01.23 14:50:48 3: Probing CUL device /dev/ttyS16

2019.01.23 14:50:48 1: CUL: Can't open /dev/ttyS16: Input/output error

2019.01.23 14:50:48 3: Probing CUL device /dev/ttyS17

2019.01.23 14:50:48 1: CUL: Can't open /dev/ttyS17: Input/output error

2019.01.23 14:50:48 3: Probing CUL device /dev/ttyS18

2019.01.23 14:50:48 1: CUL: Can't open /dev/ttyS18: Input/output error

2019.01.23 14:50:48 3: Probing CUL device /dev/ttyS19

2019.01.23 14:50:48 1: CUL: Can't open /dev/ttyS19: Input/output error

2019.01.23 14:50:48 3: Probing CUL device /dev/ttyS2

2019.01.23 14:50:48 1: CUL: Can't open /dev/ttyS2: Input/output error

2019.01.23 14:50:48 3: Probing CUL device /dev/ttyS20

2019.01.23 14:50:48 1: CUL: Can't open /dev/ttyS20: Input/output error

2019.01.23 14:50:48 3: Probing CUL device /dev/ttyS21

2019.01.23 14:50:48 1: CUL: Can't open /dev/ttyS21: Input/output error

2019.01.23 14:50:48 3: Probing CUL device /dev/ttyS22

2019.01.23 14:50:48 1: CUL: Can't open /dev/ttyS22: Input/output error

2019.01.23 14:50:48 3: Probing CUL device /dev/ttyS23

2019.01.23 14:50:48 1: CUL: Can't open /dev/ttyS23: Input/output error

2019.01.23 14:50:48 3: Probing CUL device /dev/ttyS24

2019.01.23 14:50:48 1: CUL: Can't open /dev/ttyS24: Input/output error

2019.01.23 14:50:48 3: Probing CUL device /dev/ttyS25

2019.01.23 14:50:48 1: CUL: Can't open /dev/ttyS25: Input/output error

2019.01.23 14:50:48 3: Probing CUL device /dev/ttyS26

2019.01.23 14:50:48 1: CUL: Can't open /dev/ttyS26: Input/output error

2019.01.23 14:50:48 3: Probing CUL device /dev/ttyS27

2019.01.23 14:50:48 1: CUL: Can't open /dev/ttyS27: Input/output error

2019.01.23 14:50:48 3: Probing CUL device /dev/ttyS28

2019.01.23 14:50:48 1: CUL: Can't open /dev/ttyS28: Input/output error

2019.01.23 14:50:48 3: Probing CUL device /dev/ttyS29

2019.01.23 14:50:48 1: CUL: Can't open /dev/ttyS29: Input/output error

2019.01.23 14:50:48 3: Probing CUL device /dev/ttyS3

2019.01.23 14:50:48 1: CUL: Can't open /dev/ttyS3: Input/output error

2019.01.23 14:50:48 3: Probing CUL device /dev/ttyS30

2019.01.23 14:50:48 1: CUL: Can't open /dev/ttyS30: Input/output error

2019.01.23 14:50:48 3: Probing CUL device /dev/ttyS31

2019.01.23 14:50:48 1: CUL: Can't open /dev/ttyS31: Input/output error

2019.01.23 14:50:48 3: Probing CUL device /dev/ttyS4

2019.01.23 14:50:48 1: CUL: Can't open /dev/ttyS4: Input/output error

2019.01.23 14:50:48 3: Probing CUL device /dev/ttyS5

2019.01.23 14:50:48 1: CUL: Can't open /dev/ttyS5: Input/output error

2019.01.23 14:50:48 3: Probing CUL device /dev/ttyS6

2019.01.23 14:50:48 1: CUL: Can't open /dev/ttyS6: Input/output error

2019.01.23 14:50:48 3: Probing CUL device /dev/ttyS7

2019.01.23 14:50:48 1: CUL: Can't open /dev/ttyS7: Input/output error

2019.01.23 14:50:48 3: Probing CUL device /dev/ttyS8

2019.01.23 14:50:48 1: CUL: Can't open /dev/ttyS8: Input/output error

2019.01.23 14:50:48 3: Probing CUL device /dev/ttyS9

2019.01.23 14:50:48 1: CUL: Can't open /dev/ttyS9: Input/output error

2019.01.23 14:50:48 1: usb create end

2019.01.23 14:50:48 3: Opening mqtt device xxx.xx.xx.xxx:1883

2019.01.23 14:50:48 3: mqtt device opened

2019.01.23 14:50:48 3: Opening mylgw1 device xxx.xx.xx.xx:81

2019.01.23 14:50:48 3: mylgw1 device opened

2019.01.23 14:50:48 0: Featurelevel: 5.9

2019.01.23 14:50:48 0: Server started with 240 defined entities (fhem.pl:18343/2019-01-20 perl:5.026001 os:linux user:fhem pid:8022)

2019.01.23 14:50:48 2: ZWDongle_ProcessSendStack: no ACK, resending message 0107000301020100f9

2019.01.23 14:50:48 3: harmony:discovery: new discovery response from xxx.xx.xx.xxx

2019.01.23 14:50:48 1: unknown client or client initialization error

2019.01.23 14:50:49 3: RM_HmUART_EG device opened

2019.01.23 14:50:49 1: xxx.xx.xx.xx:9090 reappeared (Stube_Kodi)

2019.01.23 14:50:49 3: harmony:discovery: new discovery response from xxx.xx.xx.xxx

2019.01.23 14:50:49 3: Stube_Harmony_Hub: connected

2019.01.23 14:50:49 3: Stube_Harmony_Hub: websocket: Switching Protocols ok

2019.01.23 14:50:49 3: harmony:discovery: new discovery response from xxx.xx.xx.xx

2019.01.23 14:50:50 3: CUL_HM set Kueche_Jalousie statusRequest

2019.01.23 14:50:50 3: Stube_Harmony_Hub: new config 

2019.01.23 14:50:51 3: CUL_HM set Schlafzimmer_Eltern_Jalousie statusRequest

2019.01.23 14:50:51 3: Stube_Harmony_Hub: new config 

2019.01.23 14:50:52 3: CUL_HM set Schlafzimmer_Eltern_Stehlampe_Sw statusRequest

2019.01.23 14:50:53 3: CUL_HM set Stube_Stehlampe_Sw statusRequest

2019.01.23 14:50:54 2: AttrTemplates: got 47 entries

2019.01.23 14:50:54 3: CUL_HM set Stube_kleine_Tischlampe_Sw statusRequest

2019.01.23 14:50:55 3: GOOGLECAST: Stube initialized successfully

2019.01.23 14:50:55 3: GOOGLECAST: Küche initialized successfully

HTTP::Message content must be bytes at /usr/share/perl5/HTTP/Request/Common.pm line 97.

2019.01.23 14:50:56 1: Including fhem.cfg

2019.01.23 14:50:56 3: WEB: port 8083 opened

2019.01.23 14:50:56 2: eventTypes: loaded 2217 events from ./log/eventTypes.txt

2019.01.23 14:50:56 3: EC3000_7918: I/O device is mylgw1

2019.01.23 14:50:56 3: EC3000_5B41: I/O device is mylgw1

2019.01.23 14:50:56 3: EC3000_4C6F: I/O device is mylgw1

2019.01.23 14:50:56 3: EC3000_D7C1: I/O device is mylgw1

2019.01.23 14:50:56 3: EC3000_D7AA: I/O device is mylgw1

2019.01.23 14:50:56 3: EC3000_75F1: I/O device is mylgw1

2019.01.23 14:50:56 3: EC3000_D792: I/O device is mylgw1

2019.01.23 14:50:56 3: EC3000_7898: I/O device is mylgw1

2019.01.23 14:50:56 3: RM_HmUART_EG device closed

2019.01.23 14:50:56 3: Opening RM_HmUART_EG device xxx.xx.xx.x:2000

2019.01.23 14:50:58 3: GOOGLECAST: GoogleCast v2.1.3

2019.01.23 14:50:58 3: GOOGLECAST: Stube initializing...

2019.01.23 14:50:58 3: telnetForBlockingFn_1548251458: port 44225 opened

2019.01.23 14:50:58 3: GOOGLECAST: Küche initializing...

2019.01.23 14:50:58 3: Opening ZWDongle1 device /dev/ttyACM0

2019.01.23 14:50:58 3: Setting ZWDongle1 serial parameters to 115200,8,N,1

2019.01.23 14:50:59 3: ZWDongle1 device opened

2019.01.23 14:50:59 3: ZWave: cannot load Crypt::Rijndael, SECURITY class disabled

2019.01.23 14:50:59 3: Opening SCC_CUL_MAX device xxx.xx.xx.xxx:2323

2019.01.23 14:51:00 3: SCC_CUL_MAX: Possible commands: mBbCFiAZGMYRTVWXef*ltuxz

2019.01.23 14:51:00 3: SCC_CUL_MAX device opened

2019.01.23 14:51:00 2: Switched SCC_CUL_MAX rfmode to MAX

2019.01.23 14:51:00 3: CUL_MAX_Check: Detected firmware version 154 of the CUL-compatible IODev

2019.01.23 14:51:01 3: TelegramBot_Define Telegram: called 

2019.01.23 14:51:01 2: VIERA: defined with host: xxx.xx.xx.x and interval: 30

2019.01.23 14:51:01 3: Kueche_LaCrosse_Temp: I/O device is mylgw1

2019.01.23 14:51:01 3: Spielzimmer_LaCrosse_Temp: I/O device is mylgw1

Reicht das?
Oder kann ich noch weitere Infos liefern?

OS: Ubuntu 18.04 / FHEM Update von gestern..Die Probleme waren aber vorher auch schon da....

Gruß
Hermann

MadMax-FHEM · 23 Januar 2019, 15:37:11

Naja es fehlt halt der wichtige Teil: was steht denn VOR dem Shutdown?

Das hier ist ja der Startvorgang und der sieht bis auf das "Probing" von etlichen USB-Devices (du solltest InitialUsbCheck abschalten) eigentlich "ok" aus (ohne jetzt das im Detail gelesen zu haben, weil: der interessante Teil ja fehlt)...

Gruß, Joachim

hermann1514 · 23 Januar 2019, 15:41:06

In der Mitte vom LOG wird ja wieder ein reboot durchgeführt...da kommen wieder die gleichen Meldungen.
Mehr steht da nicht.

USB Check habe ich nun mal deaktiviert

Gruß
Hermann

KölnSolar · 23 Januar 2019, 15:42:48

Zitat2019.01.23 14:50:43 3: Stube_Harmony_Hub: new config

HTTP::Message content must be bytes at /usr/share/perl5/HTTP/Request/Common.pm line 97.

2019.01.23 14:50:44 1: Including fhem.cfg

Die rote Meldung vor dem reboot ist ja eine Perl-(also nicht direkt FHEM)-Meldung. Ich vermute, dass das eine "die"-Meldung ist, die FHEM(Perl) in die Knie zwingt. Da davor der Harmony-Hub steht, kommt wohl von dort irgendein Blödsinn. Ich würde dieses device mal auf verbose=5 setzen, um dann beim nächsten restart ein paar mehr Infos zu haben, was der Harmony-Hub da gemacht hat.
Grüße Markus

MadMax-FHEM · 23 Januar 2019, 15:48:58

Oder GOOGLECAST...

Zitat
2019.01.23 14:50:55 3: GOOGLECAST: Stube initialized successfully

2019.01.23 14:50:55 3: GOOGLECAST: Küche initialized successfully

HTTP::Message content must be bytes at /usr/share/perl5/HTTP/Request/Common.pm line 97.

2019.01.23 14:50:56 1: Including fhem.cfg

Und ja, jetzt habe ich das auch entdeckt...
...die vielen USB-Dinger haben mich wohl verwirrt...

EDIT: ist zwar andere Meldung... Aber wer weiß: https://forum.fhem.de/index.php/topic,45505.msg893772.html#msg893772

Gruß, Joachim

nils_ · 23 Januar 2019, 15:49:37

mittendrin macht er sowas nochmal, aber anderes modul

Code Auswählen

2019.01.23 14:50:55 3: GOOGLECAST: Stube initialized successfully

2019.01.23 14:50:55 3: GOOGLECAST: Küche initialized successfully

HTTP::Message content must be bytes at /usr/share/perl5/HTTP/Request/Common.pm line 97.

2019.01.23 14:50:56 1: Including fhem.cfg

2019.01.23 14:50:56 3: WEB: port 8083 opened

//edit:
MadMax war schneller

hermann1514 · 23 Januar 2019, 15:51:04

Hi. Danke.

Die Harmony habe ich erst gestern eingebunden. Die Reboots waren vorher auch schon da.
Jetzt ist auch erst einmal wieder Ruhe. FHEM läuft seit 30 Minuten wieder "normal".

Sollte es mein Google Home sein?

Gruß
Hermann

justme1968 · 23 Januar 2019, 16:11:10

der fehler scheint aus dem perl HTTP::Request modul zukommen.

harmony verwendet das nicht.

es gibt scheinbar ein paar module die das verwenden. obwohl es keinen grund dafür gibt. die FhemHttp utils sollten ebenfalls jeden fall abdecken können und sind besser in fhem integriert als ein externes modul.

KölnSolar · 23 Januar 2019, 16:46:09

Bei mir per grep ermittelt: nur SONOS, withings, JeeLink, LaCrosseGateway, PrecipitationSensor und PatchLog.

hermann1514 · 24 Januar 2019, 12:12:35

Also, das Lacrosse Gateway setze ich auch ein.

Wie kann ich den "grep'pen" welches Modul das externe HTTP Perl benutzt?

Wuppi68 · 24 Januar 2019, 12:26:46

Zitat von: hermann1514 am 24 Januar 2019, 12:12:35
Also, das Lacrosse Gateway setze ich auch ein.

Wie kann ich den "grep'pen" welches Modul das externe HTTP Perl benutzt?

man grep

oder grep -i <Suchmuster> <Dateien> ! -i = gross/KLEIN Schreibung egal

grep HTTP::Request /opt/fhem/FHEM/*

hermann1514 · 24 Januar 2019, 12:41:27

Ah...also ein GREP auf alle Module machen....

Bei mir kommt da dann aber nur das LACROSSE Gateway in betracht. Die anderen Module nutze ich (noch) nicht.

Kann man da denn etwas ändern?

Gruß
Hermann

Wuppi68 · 24 Januar 2019, 12:51:24

Zitat von: hermann1514 am 24 Januar 2019, 12:41:27
Ah...also ein GREP auf alle Module machen....

Bei mir kommt da dann aber nur das LACROSSE Gateway in betracht. Die anderen Module nutze ich (noch) nicht.

Kann man da denn etwas ändern?

Gruß
Hermann

a) den Modul Maintainer kontaktieren
b) das Modul umprogrammieren UND dem Maintainer einen Patch zukommen lassen