FHEM Forum

FHEM => Anfängerfragen => Thema gestartet von: TiPpFeHlEr am 27 Juni 2020, 17:22:56

Titel: fhem freeze nach 2 Minuten oder sporadisch
Beitrag von: TiPpFeHlEr am 27 Juni 2020, 17:22:56
Hi Folks,

ich brauche jetzt mal doch eure Hilfe.

Hatte mit meinem alten System Pi3B+ öfter mal nen freeze von fhem, nun habe ich auf Pi4B & Buster umgestellt.
Hardware ist kpl neu.

Leider muss ich feststellen das, das System ebenfalls extrem instabil ist.
Mittlerweile reagiert FHEM nach ca. 2 Minuten start nicht mehr aufs Webinterface.
Habe mal versucht den Fehler zu finden.

systemctl status fhem.service
* fhem.service - FHEM Home Automation
   Loaded: loaded (/etc/systemd/system/fhem.service; enabled; vendor preset: enabled)
   Active: active (running) since Sat 2020-06-27 16:57:15 CEST; 16min ago
  Process: 8618 ExecStart=/usr/bin/perl fhem.pl fhem.cfg (code=exited, status=0/SUCCESS)
Main PID: 8619 (perl)
    Tasks: 21 (limit: 4915)
   Memory: 199.6M
   CGroup: /system.slice/fhem.service
           |- 8619 /usr/bin/perl fhem.pl fhem.cfg
           |-10575 /usr/bin/perl fhem.pl fhem.cfg
           |-10576 /usr/bin/perl fhem.pl fhem.cfg
           |-10577 /usr/bin/perl fhem.pl fhem.cfg
           |-10578 /usr/bin/perl fhem.pl fhem.cfg
           |-10579 /usr/bin/perl fhem.pl fhem.cfg
           |-10586 /usr/bin/perl fhem.pl fhem.cfg
           |-10587 /usr/bin/perl fhem.pl fhem.cfg
           |-10588 /usr/bin/perl fhem.pl fhem.cfg
           |-10589 /usr/bin/perl fhem.pl fhem.cfg
           |-10590 /usr/bin/perl fhem.pl fhem.cfg
           |-10591 /usr/bin/perl fhem.pl fhem.cfg
           |-10592 /usr/bin/perl fhem.pl fhem.cfg
           |-10593 /usr/bin/perl fhem.pl fhem.cfg
           |-10600 /usr/bin/perl fhem.pl fhem.cfg
           |-10601 /usr/bin/perl fhem.pl fhem.cfg
           |-10602 /usr/bin/perl fhem.pl fhem.cfg
           |-10603 /usr/bin/perl fhem.pl fhem.cfg
           |-10607 /usr/bin/perl fhem.pl fhem.cfg
           |-10629 /usr/bin/perl fhem.pl fhem.cfg
           `-10630 /usr/bin/perl fhem.pl fhem.cfg

Jun 27 16:57:14 raspberrypi systemd[1]: Starting FHEM Home Automation...
Jun 27 16:57:15 raspberrypi systemd[1]: Started FHEM Home Automation.


Eigenartig sind die vielen Prozesse?
nachdem in der LOG folgendes auftauchte
2020.06.27 17:15:07 1: Timeout for SYSMON_blockingCall reached, terminated process 10575


sagt  systemctl status fhem.service
* fhem.service - FHEM Home Automation
   Loaded: loaded (/etc/systemd/system/fhem.service; enabled; vendor preset: enabled)
   Active: active (running) since Sat 2020-06-27 16:57:15 CEST; 22min ago
  Process: 8618 ExecStart=/usr/bin/perl fhem.pl fhem.cfg (code=exited, status=0/SUCCESS)
Main PID: 8619 (perl)
    Tasks: 3 (limit: 4915)
   Memory: 88.2M
   CGroup: /system.slice/fhem.service
           |- 8619 /usr/bin/perl fhem.pl fhem.cfg
           |-11423 /usr/bin/perl fhem.pl fhem.cfg
           `-11439 /usr/bin/perl fhem.pl fhem.cfg

Jun 27 16:57:14 raspberrypi systemd[1]: Starting FHEM Home Automation...
Jun 27 16:57:15 raspberrypi systemd[1]: Started FHEM Home Automation.


FHEM ist aber immernoch nicht erreichbar.

kann mir bitte jemand weiterhelfen?

freezemon sagt in der LOG
2020.06.27 17:15:07 1: [Freezemon] FreezeMon: possible freeze starting at 17:09:03, delay is 364.866 possibly caused by: tmr-at_Exec(atTraffic) tmr-at_Exec(Lueftung_addlog) tmr-at_Exec(Tor_Status_addlog) tmr-SYSMON_Update(sysmon) tmr-MQTT::Timer(MQTT) tmr-PRESENCE_StartLocalScan(Bewegung.1) tmr-PRESENCE_StartLocalScan(Bewegung.4) tmr-PRESENCE_StartLocalScan(Bewegung.2) tmr-PRESENCE_StartLocalScan(Bewegung.3) tmr-OWDevice_UpdateValues(DS18B20_FFBEE8331604) tmr-PRESENCE_StartLocalScan(Dect_Dach) tmr-PRESENCE_StartLocalScan(Dect_Garage) tmr-PRESENCE_StartLocalScan(PC_Maik) tmr-PRESENCE_StartLocalScan(TV) tmr-PRESENCE_StartLocalScan(WebRadio) tmr-PRESENCE_StartLocalScan(PC_Andre) tmr-PRESENCE_StartLocalScan(PC_Arbeit) tmr-PRESENCE_StartLocalScan(Andre_Uhr) tmr-OWDevice_UpdateValues(DS18B20_FFC5EC331604) tmr-PRESENCE_StartLocalScan(Wemos_2) tmr-PRESENCE_StartLocalScan(DECT.Auto) tmr-PRESENCE_StartLocalScan(Wemos_1) tmr-PRESENCE_StartLocalScan(Wemos_3) tmr-OWDevice_UpdateValues(DS18B20_FF3B3B931503) tmr-FRITZBOX_Readout_Start(N/A) tmr-OWDevice_UpdateValues(DS18B20_FF8BED331604) tmr-OWDevice_UpdateValues(DS18B20_FF173C931503) tmr-OWDevice_UpdateValues(DS18B20_FFE4E5331604) tmr-OWDevice_UpdateValues(DS18B20_FFF9E9331604) tmr-BlockingKill(N/A) tmr-BlockingKill(N/A) tmr-FW_closeInactiveClients(N/A) tmr-SYSSTAT_GetUpdate(BBxM) tmr-FBAHAHTTP_Poll(Fritz_DECT) tmr-I2C_MCP342x_Poll(ADC.CH1234) tmr-PRESENCE_StartLocalScan(handy_Maik) tmr-PRESENCE_StartLocalScan(handy_Andre) tmr-at_Exec(EBUS.Timer) tmr-at_Exec(Klima_addlog)



hier mal die LOG vom fhem Start
2020.06.27 17:29:08 1: Including fhem.cfg
2020.06.27 17:29:08 2: eventTypes: loaded 2977 events from ./log/eventTypes.txt
2020.06.27 17:29:10 1: RXArduino: Can't open /dev/serial/by-id/usb-1a86_USB2.0-Serial-if00-port0: No such file or directory
2020.06.27 17:29:12 1: ERROR evaluating my $DEV='Klima_ON_Temp';my $NAME='EBUS2';my $TYPE='ECMD';my $EVTPART0='CONNECTED';my $EVENT='CONNECTED';my $SELF='Klima_Not_Temp';[Klima_Soll:state]+[Klima_Diff:state]: syntax error at (eval 128) line 1, near "Klima_Soll:"

2020.06.27 17:29:12 1: ERROR evaluating my $DEV='Klima_OFF_Temp';my $NAME='EBUS2';my $TYPE='ECMD';my $EVTPART0='CONNECTED';my $EVENT='CONNECTED';my $SELF='Klima_Not_Temp';[Klima_Soll:state]-[Klima_Diff:state]: syntax error at (eval 129) line 1, near "Klima_Soll:"

2020.06.27 17:29:12 1: Strom: Can't open /dev/serial/by-id/usb-FTDI_FT232R_USB_UART_STROM01-if00-port0: No such file or directory
2020.06.27 17:29:12 1: Tor_Serial: Can't open /dev/serial/by-id/usb-FTDI_FT232R_USB_UART_TOR01-if00-port0: No such file or directory
2020.06.27 17:29:13 1: Including fhem.save
2020.06.27 17:29:13 4: SSR1: STATE kann auf off wiederhergestellt werden 2020-06-27 17:29:13
2020.06.27 17:29:13 4: SSR1: state kann auf off wiederhergestellt werden 2020-06-27 16:57:20
2020.06.27 17:29:13 4: OUTPUT SSR1: state wiederhergestellt auf off
2020.06.27 17:29:13 5: SSR1, in fileaccess: value 0
2020.06.27 17:29:13 5: SSR1, in fileaccess: direction high
2020.06.27 17:29:13 4: SSR1: direction gesetzt auf high
2020.06.27 17:29:13 4: OUTPUT SSR1: STATE wiederhergestellt auf off (restoreOnStartup=last)
2020.06.27 17:29:13 1: Messages collected while initializing FHEM:SecurityCheck:
  WEBtablet is not password protected
  telnetPort is not password protected

Protect this FHEM installation by configuring the allowed device allowed_WEB
You can disable this message with attr global motd none

2020.06.27 17:29:13 2: FB_CALLMONITOR (Fritz_Box_Monitor) - could not read FritzBox phonebook file - Can't open /home/pi/fhem/FHEM/buch.xml: No such file or directory
2020.06.27 17:29:14 5: im init client fuer ADC.CH1234
2020.06.27 17:29:14 5: ADC.CH1234: Init Argumente1: ARRAY(0x4192c30)
2020.06.27 17:29:16 5: DS1420_BF4139000000: initial delay: 1
2020.06.27 17:29:17 2: [Freezemon] FreezeMon: ready to watch out for delays greater than 1 second(s)
2020.06.27 17:29:17 0: Featurelevel: 6
2020.06.27 17:29:17 0: Server started with 686 defined entities (fhem.pl:22200/2020-06-19 perl:5.028001 os:linux user:fhem pid:13394)
2020.06.27 17:29:18 5: myI2C: vom client empfangen|i2caddress: 104|data: 141|direction: i2cwrite
2020.06.27 17:29:18 5: myI2C: HWaccess I2CAddr: 0x68
2020.06.27 17:29:18 5: myI2C: vom client empfangen|i2caddress: 104|data: 141|direction: i2cwrite
2020.06.27 17:29:18 5: myI2C: HWaccess block schreiben,  Inh(dec):|141|, laenge: |1|
2020.06.27 17:29:18 5: myI2C ->Client gefunden: ADC.CH1234, I2Caddress: 104 Data: 141
2020.06.27 17:29:19 5: myI2C: vom client empfangen|direction: i2cread|nbyte: 5|i2caddress: 104
2020.06.27 17:29:19 5: myI2C: HWaccess I2CAddr: 0x68
2020.06.27 17:29:19 5: myI2C: vom client empfangen|direction: i2cread|nbyte: 5|i2caddress: 104
2020.06.27 17:29:19 5: myI2C ->Client gefunden: ADC.CH1234, I2Caddress: 104 Gelesen: 1 166 218 13 13
2020.06.27 17:29:19 4: Kanal: 1, rawvolt: 108250, Aufloesung: 18, Gain: 2, LSB: 15.625
2020.06.27 17:29:19 4: Kanal: 1, Signedrawvolt: 108250
2020.06.27 17:29:19 5: myI2C: vom client empfangen|direction: i2cwrite|data: 173|i2caddress: 104
2020.06.27 17:29:19 5: myI2C: HWaccess I2CAddr: 0x68
2020.06.27 17:29:19 5: myI2C: vom client empfangen|direction: i2cwrite|data: 173|i2caddress: 104
2020.06.27 17:29:19 5: myI2C: HWaccess block schreiben,  Inh(dec):|173|, laenge: |1|
2020.06.27 17:29:19 5: myI2C ->Client gefunden: ADC.CH1234, I2Caddress: 104 Data: 173
2020.06.27 17:29:19 5: myI2C: vom client empfangen|i2caddress: 104|nbyte: 5|direction: i2cread
2020.06.27 17:29:19 5: myI2C: HWaccess I2CAddr: 0x68
2020.06.27 17:29:19 5: myI2C: vom client empfangen|i2caddress: 104|nbyte: 5|direction: i2cread
2020.06.27 17:29:19 5: myI2C ->Client gefunden: ADC.CH1234, I2Caddress: 104 Gelesen: 1 46 55 45 45
2020.06.27 17:29:19 4: Kanal: 2, rawvolt: 77367, Aufloesung: 18, Gain: 2, LSB: 15.625
2020.06.27 17:29:19 4: Kanal: 2, Signedrawvolt: 77367
2020.06.27 17:29:19 5: myI2C: vom client empfangen|direction: i2cwrite|data: 205|i2caddress: 104
2020.06.27 17:29:19 5: myI2C: HWaccess I2CAddr: 0x68
2020.06.27 17:29:19 5: myI2C: vom client empfangen|direction: i2cwrite|data: 205|i2caddress: 104
2020.06.27 17:29:19 5: myI2C: HWaccess block schreiben,  Inh(dec):|205|, laenge: |1|
2020.06.27 17:29:19 5: myI2C ->Client gefunden: ADC.CH1234, I2Caddress: 104 Data: 205
2020.06.27 17:29:19 5: myI2C: vom client empfangen|nbyte: 5|direction: i2cread|i2caddress: 104
2020.06.27 17:29:19 5: myI2C: HWaccess I2CAddr: 0x68
2020.06.27 17:29:19 5: myI2C: vom client empfangen|nbyte: 5|direction: i2cread|i2caddress: 104
2020.06.27 17:29:19 5: myI2C ->Client gefunden: ADC.CH1234, I2Caddress: 104 Gelesen: 1 210 56 77 77
2020.06.27 17:29:19 4: Kanal: 3, rawvolt: 119352, Aufloesung: 18, Gain: 2, LSB: 15.625
2020.06.27 17:29:19 4: Kanal: 3, Signedrawvolt: 119352
2020.06.27 17:29:19 5: myI2C: vom client empfangen|i2caddress: 104|data: 237|direction: i2cwrite
2020.06.27 17:29:19 5: myI2C: HWaccess I2CAddr: 0x68
2020.06.27 17:29:19 5: myI2C: vom client empfangen|i2caddress: 104|data: 237|direction: i2cwrite
2020.06.27 17:29:19 5: myI2C: HWaccess block schreiben,  Inh(dec):|237|, laenge: |1|
2020.06.27 17:29:19 5: myI2C ->Client gefunden: ADC.CH1234, I2Caddress: 104 Data: 237
2020.06.27 17:29:20 5: myI2C: vom client empfangen|nbyte: 5|direction: i2cread|i2caddress: 104
2020.06.27 17:29:20 5: myI2C: HWaccess I2CAddr: 0x68
2020.06.27 17:29:20 5: myI2C: vom client empfangen|nbyte: 5|direction: i2cread|i2caddress: 104
2020.06.27 17:29:20 5: myI2C ->Client gefunden: ADC.CH1234, I2Caddress: 104 Gelesen: 0 163 5 109 109
2020.06.27 17:29:20 4: Kanal: 4, rawvolt: 41733, Aufloesung: 18, Gain: 2, LSB: 15.625
2020.06.27 17:29:20 4: Kanal: 4, Signedrawvolt: 41733
2020.06.27 17:29:20 2: Moving BBxM-2019-11.log to /opt/fhem/archive/
2020.06.27 17:29:20 1: Rename: Cannot open /opt/fhem/archive//BBxM-2019-11.log: No such file or directory
2020.06.27 17:29:20 2: Moving BBxM-2019-12.log to /opt/fhem/archive/
2020.06.27 17:29:20 1: Rename: Cannot open /opt/fhem/archive//BBxM-2019-12.log: No such file or directory
2020.06.27 17:29:20 2: Moving BBxM-2020-01.log to /opt/fhem/archive/
2020.06.27 17:29:20 1: Rename: Cannot open /opt/fhem/archive//BBxM-2020-01.log: No such file or directory
2020.06.27 17:29:20 2: Moving BBxM-2020-02.log to /opt/fhem/archive/
2020.06.27 17:29:20 1: Rename: Cannot open /opt/fhem/archive//BBxM-2020-02.log: No such file or directory
2020.06.27 17:29:20 2: Moving BBxM-2020-03.log to /opt/fhem/archive/
2020.06.27 17:29:20 1: Rename: Cannot open /opt/fhem/archive//BBxM-2020-03.log: No such file or directory
2020.06.27 17:29:20 2: Moving BBxM-2020-04.log to /opt/fhem/archive/
2020.06.27 17:29:20 1: Rename: Cannot open /opt/fhem/archive//BBxM-2020-04.log: No such file or directory
2020.06.27 17:29:20 1: [Freezemon] FreezeMon: possible freeze starting at 17:29:18, delay is 2.927 possibly caused by: no bad guy found :-(
2020.06.27 17:29:27 1: [Freezemon] FreezeMon: possible freeze starting at 17:29:26, delay is 1.621 possibly caused by: tmr-OWDevice_UpdateValues(DS18B20_FF3B3B931503) tmr-OWDevice_UpdateValues(DS18B20_FFE4E5331604)



MfG Maik
Titel: Antw:fhem freeze nach 2 Minuten
Beitrag von: feger am 27 Juni 2020, 18:40:09
Hallo!

Ich bin jetzt zwar nicht so der Experte aber was mir auf die schnelle einfällt:
1. Ist die SD Karte auch neu?
2. Updates gemacht?
3. Start Konfig bereinigen, damit die Fehlermeldungen verschwinden.
4. Eventuell ein Netzwerk Problem?
5. wird FHEM vom Raspberry 4 voll unterstützt?

mfg Feger
Titel: Antw:fhem freeze nach 2 Minuten
Beitrag von: amenomade am 27 Juni 2020, 18:41:40
5. => ja
Titel: Antw:fhem freeze nach 2 Minuten
Beitrag von: amenomade am 27 Juni 2020, 18:50:00
@Maik: Du hast anscheinend mehrere Probleme
- die I/O Geräte werden nicht bzw nicht mehr unter dem gleichen Name erkannt. Oder die Berechtigungen drauf erlauben fhem nicht. Da musst du in /dev/serial/by-id/ einmal schauen
- Can't open /home/pi/fhem/FHEM/buch.xml => Datei nicht da oder Berechtigungsproblem
- Cannot open /opt/fhem/archive//BBxM-2019-11.log: No such file or directory => gleiches Problem

Wenn das schon mal gelöst ist, wird die Log schon hoffentlich sauberer sein. Dann sehen wir wieder, ob andere Probleme auftauchen.
Titel: Antw:fhem freeze nach 2 Minuten
Beitrag von: TiPpFeHlEr am 27 Juni 2020, 19:45:18
also

1. JA -> habe jetzt ne ssd bestellt und werden den USBboot vom pi4 probieren
2. jupp OS & FHEM alles aktuell
3. ?
4. nein -> der pi ist über ssh voll ansprechbar und ist mit 1% asugelastet (fhem.perl)
5. öhm da gehe ich doch von aus ;)

das Problem mit den /dev/serial/by-id/..... war der USB HUB -
dies ist eines der Probleme, das USB Geräte immerwieder nicht erreichbar sind
zB. Serial Adapter, EBUS Adapter, .....
dies betrifft auch Geräte die direkt am pi hängen, es ist nun schon der xte USB HUB mit externer Stromversorgung den ich teste.
Hab den pi kpl neu gestartet, /dev/serial/by-id/... wieder ereichbar

das Problem mit /opt/fhem/archive//BBxM-2019-11.log: No such file or directory -> den Ordner gibts nicht
sollte der existieren?
muss ich den Ordner selber erstellen oder tut das eigentlich fhem oder das Modul?

im Augenblick läuft der pi und fhem ist ohne Probleme erreichbar.

gibts weitere Ansätze zum loggen im System um herrauszufinden warum bei 1% CPU Last (fhem.perl) Fhem nicht reagiert?

MfG Maik
Titel: Antw:fhem freeze nach 2 Minuten
Beitrag von: amenomade am 27 Juni 2020, 19:59:44
ZitatProblem mit /opt/fhem/archive//BBxM-2019-11.log: No such file or directory
Ich glaube, fhem erstellt das selbst. Wobei das doppelte Schrägstricht merkwürdig ist. Was sind das für Devices?
NB: das Berechtigungsproblem kann auch auf dem "archive" Ordner sein.

Zitatgibts weitere Ansätze zum loggen im System um herrauszufinden warum bei 1% CPU Last (fhem.perl) Fhem nicht reagiert?

- verbose 5
- Fhem im Debug Modus starten
- apptime https://wiki.fhem.de/wiki/Apptime
- perfmon / freezemon hast Du anscheinend schon

Aber wenn beim Start schon so viele Fehlermeldungen in der Log zu lesen sind, müsste man die zuerst korrigieren ;)
Titel: Antw:fhem freeze nach 2 Minuten
Beitrag von: TiPpFeHlEr am 27 Juni 2020, 22:22:10
Hi amenomade

1. verbose 5 hatte ich im global nicht an, weil sonst die LOG so gross wird
2. DEBUG Modus kenne ich noch nicht -> schaue ich mir an
3. apptime ist drauf, und hat nur gemeckert das (OWFS,EBUSD,ECMD) sehr lange brauchen -> hier liegt aber nicht der Grund
4. freezmon ist drauf und zeigt eigentlich das gleiche wie apptime
    perfmon kenne ich noch nicht -> schau ich mir an

Die Fehlermeldungen am start sind jetzt weg, seitdem der USB HUB wieder geht

das Seltsame ist, wenn das Problem auftritt, ist die Auslastung nur ca. 1%.
RAM ist nur zu 10% voll
SWAP ist fast leer
mmc oder sda IO ist fast 0

laut den Werten spricht nichts dagegen das fhem seine Arbeit tun müsste, tuts aber nicht.
Es scheint als ob fhem.perl in einer Schleife hängt, und nicht weiter macht.
Einmal fiel auf das in dem Augenblick des freeze keine LOG Einträge in der fhem.log mehr erschienen sind.

Ich wüsste halt gerne in welcher Schleife fhem steckt oder auf welchen Job er wartet.

MfG
Titel: Antw:fhem freeze nach 2 Minuten
Beitrag von: feger am 27 Juni 2020, 22:52:52
Zitat von: TiPpFeHlEr am 27 Juni 2020, 19:45:18
das Problem mit /opt/fhem/archive//BBxM-2019-11.log: No such file or directory -> den Ordner gibts nicht
sollte der existieren?
muss ich den Ordner selber erstellen oder tut das eigentlich fhem oder das Modul?
Also ich habe den Ordner auch nicht.

Blockiert FHEM komplett (eventuell Lampe einschalten,...) oder nur die Web Oberfläche?
Siehst du vielleicht mit top welcher Prozeß blockiert?
Eventuell einen Prozeß nach dem anderen killen und schauen ob es wieder geht.

Mir ist schon mal aufgefallen, als mein Internet Router sich verabschiedet hat, das Fhem sehr träge reagiert hat.
Vielleicht kommt dein Raspi zeitweise auch nicht ins Internet?
Wenn er blockiert und du wartest funktioniert es nach einer Weile wieder?
mfg Feger
Titel: Antw:fhem freeze nach 2 Minuten
Beitrag von: amenomade am 27 Juni 2020, 23:01:58
ZitatEinmal fiel auf das in dem Augenblick des freeze keine LOG Einträge in der fhem.log mehr erschienen sind.
Auch wenn in dem Augenblick Fhem nichts mehr schreibt, könnten die letzte Loganträge vor dem freeze interessant sein.

fhem im Debug Modus macht nichts anderes als verbose 5 + alles in der Console statt in den Logs zu schreiben

perfmon wird dir hier nicht viel helfen, da Du schon freezemon im Betrieb hast.

Was liefert denn apptime?

PS: die Antworte auf die Fragen von feger wären auch interessant.

EDIT: und checke, dass das Attribut dnsServer auf global gesetzt ist, sonst werden viele Http Abfragen "blocking" ausgeführt.
Titel: Antw:fhem freeze nach 2 Minuten
Beitrag von: TiPpFeHlEr am 28 Juni 2020, 07:40:58
@feger

ZitatBlockiert FHEM komplett (eventuell Lampe einschalten,...) oder nur die Web Oberfläche?
manchmal so, manchmal so.
Im Normalfall nur die WEB Oberfläche
Gestern aber auch die Grundlegende Funktion, wie zB. Telegramm, DECT, OWFS, also alles
Der pi an sich ließ sich über ssh perfekt ansprechen

ZitatSiehst du vielleicht mit top welcher Prozeß blockiert?
Eben nicht, der einzige Prozess der etwas tut ist fhem.perl 1-2% und ab und zu chrome(KIOSK Mode) 0-20%
Es gibt keinen Prozess mit zb. 100% der das system blockiert.

ZitatEventuell einen Prozeß nach dem anderen killen und schauen ob es wieder geht.
Gute Idee, aber mit welchem fängt man an  ;D

ZitatVielleicht kommt dein Raspi zeitweise auch nicht ins Internet?
Gute Frage, wie sehe ich ob er im I-Net ist?
Hmmm... ich könnte google anpingen?

@amenomade

ZitatWas liefert denn apptime?
active-timers: 59; max-active timers: 59; max-timer-load: 2  min-tmrHandlingTm: 0.4ms; max-tmrHandlingTm: 1015.5ms; totAvgDly: 124.0ms

name                                     function                               max    count      total  average   maxDly   avgDly TS Max call     param Max call
tmr-OWDevice_UpdateValues                HASH(0x4497030)                       1011        1    1011.50  1011.50     1.81     1.81 28.06. 07:37:51 HASH(DS18B20_FFBEE8331604)
tmr-OWDevice_UpdateValues                HASH(0x4492728)                        822        1     822.42   822.42     1.81     1.81 28.06. 07:37:54 HASH(DS18B20_FF3B3B931503)
WEBphone_192.168.2.34_52998              FW_Read                                192        4     197.02    49.26     0.00     0.00 28.06. 07:37:48 HASH(WEBphone_192.168.2.34_52998)
Luftung_not_temp                         notify_Exec                             54        1      54.76    54.76     0.00     0.00 28.06. 07:37:54 HASH(Luftung_not_temp); HASH(DS18B20_FF3B3B931503)
Automatik_Klima                          DOIF_Notify                              8        1       8.33     8.33     0.00     0.00 28.06. 07:37:51 HASH(Automatik_Klima); HASH(DS18B20_FFBEE8331604)
Automatik_WT                             DOIF_Notify                              8        5      28.93     5.79     0.00     0.00 28.06. 07:37:54 HASH(Automatik_WT); HASH(DS18B20_FF3B3B931503)
tmr-freezemon_ProcessTimer               HASH(0x5193838)                          3       13       7.10     0.55  1013.41   142.80 28.06. 07:37:51 HASH(FreezeMon)
allowed_WEB                              allowed_Authorize                        1     1389      14.66     0.01     0.00     0.00 28.06. 07:37:48 HASH(allowed_WEB); HASH(WEBphone_192.168.2.34_52998); devicename; DECT_STD.2_doif; 1
WEBphone_192.168.2.34_52994              FW_Read                                  1        3       2.60     0.87     0.00     0.00 28.06. 07:37:40 HASH(WEBphone_192.168.2.34_52994)
WEBphone_192.168.2.34_52996              FW_Read                                  0        3       2.14     0.71     0.00     0.00 28.06. 07:37:40 HASH(WEBphone_192.168.2.34_52996)
FileLog_Fuehler1                         FileLog_Log                              0        1       0.97     0.97     0.00     0.00 28.06. 07:37:54 HASH(FileLog_Fuehler1); HASH(DS18B20_FF3B3B931503)
WEBphone_192.168.2.34_53000              FW_Read                                  0        4       2.08     0.52     0.00     0.00 28.06. 07:37:40 HASH(WEBphone_192.168.2.34_53000)
WEBphone_192.168.2.34_53002              FW_Read                                  0        2       1.59     0.79     0.00     0.00 28.06. 07:37:40 HASH(WEBphone_192.168.2.34_53002)
FileLog_WT_Temps                         FileLog_Log                              0        4       2.17     0.54     0.00     0.00 28.06. 07:37:54 HASH(FileLog_WT_Temps); HASH(WT_Temps)
Auto_dummy_not                           notify_Exec                              0        8       2.42     0.30     0.00     0.00 28.06. 07:37:54 HASH(Auto_dummy_not); HASH(DS18B20_FF3B3B931503)
FileLog_Bewegung_Ankleide                FileLog_Log                              0        8       2.02     0.25     0.00     0.00 28.06. 07:37:54 HASH(FileLog_Bewegung_Ankleide); HASH(DS18B20_FF3B3B931503)
Phase3_log                               FileLog_Log                              0        8       2.14     0.27     0.00     0.00 28.06. 07:37:54 HASH(Phase3_log); HASH(WT_Temps)
WEBphone                                 FW_Read                                  0        5       2.01     0.40     0.00     0.00 28.06. 07:37:40 HASH(WEBphone)
StromKG_log                              FileLog_Log                              0        8       2.29     0.29     0.00     0.00 28.06. 07:37:54 HASH(StromKG_log); HASH(WT_Temps)
Phase1_log                               FileLog_Log                              0        8       2.36     0.29     0.00     0.00 28.06. 07:37:54 HASH(Phase1_log); HASH(WT_Temps)
Phase2_log                               FileLog_Log                              0        8       2.05     0.26     0.00     0.00 28.06. 07:37:54 HASH(Phase2_log); HASH(WT_Temps)
eventTypes                               eventTypes_Notify                        0        8       1.52     0.19     0.00     0.00 28.06. 07:37:54 HASH(eventTypes); HASH(WT_Temps)
FileLog_Fuehler6                         FileLog_Log                              0        1       0.34     0.34     0.00     0.00 28.06. 07:37:51 HASH(FileLog_Fuehler6); HASH(DS18B20_FFBEE8331604)
Fritzstatus                              readingsGroup_Notify                     0        8       1.18     0.15     0.00     0.00 28.06. 07:37:54 HASH(Fritzstatus); HASH(DS18B20_FF3B3B931503)
Bewegung_4_off                           notify_Exec                              0        8       1.68     0.21     0.00     0.00 28.06. 07:37:54 HASH(Bewegung_4_off); HASH(WT_Temps)
Auto_not                                 notify_Exec                              0        8       1.53     0.19     0.00     0.00 28.06. 07:37:54 HASH(Auto_not); HASH(WT_Temps)
Bewegung_4_on                            notify_Exec                              0        8       1.32     0.17     0.00     0.00 28.06. 07:37:54 HASH(Bewegung_4_on); HASH(WT_Temps)
Logfile                                  FileLog_Log                              0        8       1.27     0.16     0.00     0.00 28.06. 07:37:54 HASH(Logfile); HASH(DS18B20_FF3B3B931503)
allowed_WEBphone                         allowed_Authenticate                     0        5       0.87     0.17     0.00     0.00 28.06. 07:37:40 HASH(allowed_WEBphone); HASH(WEBphone_192.168.2.34_52994); HASH(0x23698a0)
Anwesenheit                              structure_Notify                         0        8       0.60     0.07     0.00     0.00 28.06. 07:37:54 HASH(Anwesenheit); HASH(DS18B20_FF3B3B931503)
FreezeMon                                freezemon_Notify                         0        8       0.60     0.07     0.00     0.00 28.06. 07:37:54 HASH(FreezeMon); HASH(WT_Temps)
allowed_WEBtablet                        allowed_Authorize                        0     1389      14.19     0.01     0.00     0.00 28.06. 07:37:48 HASH(allowed_WEBtablet); HASH(WEBphone_192.168.2.34_52998); devicename; Aussentemp; 1
allowed_WEBphone                         allowed_Authorize                        0     1389      28.15     0.02     0.00     0.00 28.06. 07:37:48 HASH(allowed_WEBphone); HASH(WEBphone_192.168.2.34_52998); devicename; Bewegung_2_on; 1
WEBphone_192.168.2.34_52998              FW_Notify                                0        8       0.23     0.03     0.00     0.00 28.06. 07:37:54 HASH(WEBphone_192.168.2.34_52998); HASH(WT_Temps)
WEB                                      FW_Notify                                0        8       0.15     0.02     0.00     0.00 28.06. 07:37:54 HASH(WEB); HASH(WT_Temps)
allowed_WEB                              allowed_Authenticate                     0        5       0.18     0.04     0.00     0.00 28.06. 07:37:40 HASH(allowed_WEB); HASH(WEBphone_192.168.2.34_52994); HASH(0x23698a0)
WEBphone_192.168.2.61_50212              FW_Notify                                0        8       0.13     0.02     0.00     0.00 28.06. 07:37:54 HASH(WEBphone_192.168.2.61_50212); HASH(WT_Temps)
WEBphone_192.168.2.61_50296              FW_Notify                                0        8       0.11     0.01     0.00     0.00 28.06. 07:37:54 HASH(WEBphone_192.168.2.61_50296); HASH(WT_Temps)
WEBphone_192.168.2.61_53876              FW_Notify                                0        8       0.11     0.01     0.00     0.00 28.06. 07:37:54 HASH(WEBphone_192.168.2.61_53876); HASH(WT_Temps)
WEBtablet_127.0.0.1_47052                FW_Notify                                0        8       0.11     0.01     0.00     0.00 28.06. 07:37:54 HASH(WEBtablet_127.0.0.1_47052); HASH(WT_Temps)
WEBphone                                 FW_Notify                                0        8       0.05     0.01     0.00     0.00 28.06. 07:37:54 HASH(WEBphone); HASH(WT_Temps)



ZitatEDIT: und checke, dass das Attribut dnsServer auf global gesetzt ist, sonst werden viele Http Abfragen "blocking" ausgeführt.
also
attr global dnsServer global?

p.s. der pi läuft seit gestern (14h) ohne Probleme

MfG Maik
Titel: Antw:fhem freeze nach 2 Minuten oder sporadisch
Beitrag von: TiPpFeHlEr am 28 Juni 2020, 09:27:40
Mal ne Frage zu freezemon

was bedeutet das genau?[Freezemon] FreezeMon: possible freeze starting at 09:24:29, delay is 12.922 possibly caused by: tmr-at_Exec(EBUS.Timer)

der EBUS.Timer fragt den EBUS der Vaillant Heizung auf neue Werte ab, das dauert natürlich etwas, hängt fhem in dieser Zeit oder sind die 13 Sekunden nur die Zeit von Beginn bis Ende.?

MfG Maik
Titel: Antw:fhem freeze nach 2 Minuten oder sporadisch
Beitrag von: KölnSolar am 28 Juni 2020, 12:06:11
Sowohl als auch. FHEM dürfte f. die Dauer von 13s blockiert sein.

Es muss aber nicht tmr-at_Exec(EBUS.Timer) sein. Genauer lässt sich das über das freezemon-Logfile analysieren.
Grüße Markus
Titel: Antw:fhem freeze nach 2 Minuten oder sporadisch
Beitrag von: TiPpFeHlEr am 28 Juni 2020, 12:09:43
Es ist wieder passiert :(

Bin grad nicht zu Hause, aber aus der Ferne kann ich festellen das Telegramm nicht mehr antwortet.
letzte Aktion war ein serial ECMD device das fhem den Status des Tor 's mitteilte.

Werde nachher mal alle logs anschauen und berichten.

Mfg Maik
Titel: Antw:fhem freeze nach 2 Minuten
Beitrag von: amenomade am 28 Juni 2020, 12:48:22
Zitat von: TiPpFeHlEr am 28 Juni 2020, 07:40:58

also
attr global dnsServer global?

Ne, eher attr global dnsServer <IP deiner Box> oder von welchem Gerät auch immer, das die DNS Auflösung für dich macht. Das was hier steht ist aber grundsätzlich nicht wichtig für die HTTP Gets, nur... das Attribut muss gesetzt werden, damit die HTTP Gets non-blocking ausgeführt werden. Ein vernünftiger Wert wie <IP deiner Box> hilft aber bei der DNS Auflösung selbst, die immer "blocking" erfolgt.
Titel: Antw:fhem freeze nach 2 Minuten oder sporadisch
Beitrag von: TiPpFeHlEr am 28 Juni 2020, 16:23:57
So wie versprochen der Aktuelle Stand (Stillstand)  :(

Der pi ist per ssh normal erreichbar.
ping zu google geht
MQTT geht
OWFS Server läuft & ist erreichbar

systemctl status fhem.service
* fhem.service - FHEM Home Automation
   Loaded: loaded (/etc/systemd/system/fhem.service; enabled; vendor preset: enabled)
   Active: active (running) since Sat 2020-06-27 17:19:26 CEST; 22h ago
  Process: 531 ExecStart=/usr/bin/perl fhem.pl fhem.cfg (code=exited, status=0/SUCCESS)
Main PID: 735 (perl)
    Tasks: 2 (limit: 4915)
   Memory: 2.3G
   CGroup: /system.slice/fhem.service
           |- 735 /usr/bin/perl fhem.pl fhem.cfg
           `-6137 /usr/bin/perl fhem.pl fhem.cfg

Jun 27 21:00:00 raspberrypi irsend[4134]: lirc_command_run, state: 1, input: "SEND_ONCE Klima KEY_0"
Jun 27 21:00:00 raspberrypi irsend[4134]: lirc_command_run, state: 2, input: "SUCCESS"
Jun 27 21:00:00 raspberrypi irsend[4134]: lirc_command_run, state: 3, input: "END"
Jun 27 21:00:00 raspberrypi irsend[4134]: lirc_command_run: data:END, status:0
Jun 28 07:00:00 raspberrypi irsend[21667]: lirc_command_run: Sending: SEND_ONCE Klima KEY_POWER 2
Jun 28 07:00:00 raspberrypi irsend[21667]: lirc_command_run, state: 0, input: "BEGIN"
Jun 28 07:00:00 raspberrypi irsend[21667]: lirc_command_run, state: 1, input: "SEND_ONCE Klima KEY_POWER 2"
Jun 28 07:00:00 raspberrypi irsend[21667]: lirc_command_run, state: 2, input: "SUCCESS"
Jun 28 07:00:00 raspberrypi irsend[21667]: lirc_command_run, state: 3, input: "END"
Jun 28 07:00:00 raspberrypi irsend[21667]: lirc_command_run: data:END, status:0


die letzte Aktion des pi war, mir per telegramm eine Message schicken das das Tor fährt.
Danach ging nix mehr, dies war um 11:21 .

seit dem tauch in der fhem.log immerwieder folgendes auf
2020.06.28 11:25:19 1: PERL WARNING: Argument "ERR: no signal\n\n" isn't numeric in sprintf at (eval 389703) line 1.
2020.06.28 11:25:34 1: PERL WARNING: Argument "ERR: no signal\n\n" isn't numeric in sprintf at (eval 389732) line 1.
2020.06.28 11:25:49 1: PERL WARNING: Argument "ERR: no signal\n\n" isn't numeric in sprintf at (eval 389761) line 1.
2020.06.28 11:25:49 1: PERL WARNING: Argument "ERR: no signal\n\n" isn't numeric in sprintf at (eval 389764) line 1.
2020.06.28 11:26:04 1: PERL WARNING: Argument "ERR: no signal\n\n" isn't numeric in sprintf at (eval 389792) line 1.
2020.06.28 11:26:10 1: PERL WARNING: Argument "" isn't numeric in sprintf at (eval 389804) line 1.
2020.06.28 11:26:19 1: PERL WARNING: Argument "ERR: no signal\n\n" isn't numeric in sprintf at (eval 389821) line 1.
2020.06.28 11:26:55 1: PERL WARNING: Argument "ERR: no signal\n\n" isn't numeric in sprintf at (eval 389890) line 1.
2020.06.28 11:27:01 1: PERL WARNING: Argument "" isn't numeric in sprintf at (eval 389902) line 1.
2020.06.28 11:27:34 1: PERL WARNING: Argument "ERR: no signal\n\n" isn't numeric in division (/) at (eval 389967) line 1.
2020.06.28 11:28:49 1: PERL WARNING: Argument "ERR: no signal\n\n" isn't numeric in sprintf at (eval 390130) line 1.
2020.06.28 11:29:01 1: PERL WARNING: Argument "" isn't numeric in sprintf at (eval 390155) line 1.
2020.06.28 11:29:10 1: PERL WARNING: Argument "" isn't numeric in sprintf at (eval 390178) line 1.
2020.06.28 11:29:19 1: PERL WARNING: Argument "ERR: no signal\n\n" isn't numeric in sprintf at (eval 390199) line 1.
2020.06.28 11:29:31 1: PERL WARNING: Argument "" isn't numeric in sprintf at (eval 390230) line 1.
2020.06.28 11:29:55 5: ECMDDevice: Analyze command >{"w -c recoV Heatrecovery ".ReadingsVal("WTMode_Einstellen","state",0)."\n"}<
2020.06.28 11:29:59 5: Postprocessing "usage: write [-s QQ] [-d ZZ] -c CIRCUIT NAME [VALUE[;VALUE]*]\n  or:  write [-s QQ] [-d ZZ] -def DEFINITION [VALUE[;VALUE]*] (only if enabled)\n  or:  write [-s QQ] [-c CIRCUIT] -h ZZPBSBNN[DD]*\n Write value(s) or hex message.\n  -s QQ        override source address QQ\n  -d ZZ        override destination address ZZ\n  -c CIRCUIT   CIRCUIT of the message to send\n  NAME         NAME of the message to send\n  VALUE        a single field VALUE\n  -def         write with explicit message definition (only if enabled):\n    DEFINITION message definition to use instead of known definition\n  -h           send hex write message:\n    ZZ         destination address\n    PB SB      primary/secondary command byte\n    NN         number of following data bytes\n    DD         data byte(s) to send\n\n (\165\163\141\147\145\072\040\167\162\151\164\145\040\133\055\163\040\121\121\135\040\133\055\144\040\132\132\135\040\055\143\040\103\111\122\103\125\111\124\040\116\101\115\105\040\133\126\101\114\125\105\133\073\126\101\114\125\105\135\052\135\012\040\040\157\162\072\040\040\167\162\151\164\145\040\133\055\163\040\121\121\135\040\133\055\144\040\132\132\135\040\055\144\145\146\040\104\105\106\111\116\111\124\111\117\116\040\133\126\101\114\125\105\133\073\126\101\114\125\105\135\052\135\040\050\157\156\154\171\040\151\146\040\145\156\141\142\154\145\144\051\012\040\040\157\162\072\040\040\167\162\151\164\145\040\133\055\163\040\121\121\135\040\133\055\143\040\103\111\122\103\125\111\124\135\040\055\150\040\132\132\120\102\123\102\116\116\133\104\104\135\052\012\040\127\162\151\164\145\040\166\141\154\165\145\050\163\051\040\157\162\040\150\145\170\040\155\145\163\163\141\147\145\056\012\040\040\055\163\040\121\121\040\040\040\040\040\040\040\040\157\166\145\162\162\151\144\145\040\163\157\165\162\143\145\040\141\144\144\162\145\163\163\040\121\121\012\040\040\055\144\040\132\132\040\040\040\040\040\040\040\040\157\166\145\162\162\151\144\145\040\144\145\163\164\151\156\141\164\151\157\156\040\141\144\144\162\145\163\163\040\132\132\012\040\040\055\143\040\103\111\122\103\125\111\124\040\040\040\103\111\122\103\125\111\124\040\157\146\040\164\150\145\040\155\145\163\163\141\147\145\040\164\157\040\163\145\156\144\012\040\040\116\101\115\105\040\040\040\040\040\040\040\040\040\116\101\115\105\040\157\146\040\164\150\145\040\155\145\163\163\141\147\145\040\164\157\040\163\145\156\144\012\040\040\126\101\114\125\105\040\040\040\040\040\040\040\040\141\040\163\151\156\147\154\145\040\146\151\145\154\144\040\126\101\114\125\105\012\040\040\055\144\145\146\040\040\040\040\040\040\040\040\040\167\162\151\164\145\040\167\151\164\150\040\145\170\160\154\151\143\151\164\040\155\145\163\163\141\147\145\040\144\145\146\151\156\151\164\151\157\156\040\050\157\156\154\171\040\151\146\040\145\156\141\142\154\145\144\051\072\012\040\040\040\040\104\105\106\111\116\111\124\111\117\116\040\155\145\163\163\141\147\145\040\144\145\146\151\156\151\164\151\157\156\040\164\157\040\165\163\145\040\151\156\163\164\145\141\144\040\157\146\040\153\156\157\167\156\040\144\145\146\151\156\151\164\151\157\156\012\040\040\055\150\040\040\040\040\040\040\040\040\040\040\040\163\145\156\144\040\150\145\170\040\167\162\151\164\145\040\155\145\163\163\141\147\145\072\012\040\040\040\040\132\132\040\040\040\040\040\040\040\040\040\144\145\163\164\151\156\141\164\151\157\156\040\141\144\144\162\145\163\163\012\040\040\040\040\120\102\040\123\102\040\040\040\040\040\040\160\162\151\155\141\162\171\057\163\145\143\157\156\144\141\162\171\040\143\157\155\155\141\156\144\040\142\171\164\145\012\040\040\040\040\116\116\040\040\040\040\040\040\040\040\040\156\165\155\142\145\162\040\157\146\040\146\157\154\154\157\167\151\156\147\040\144\141\164\141\040\142\171\164\145\163\012\040\040\040\040\104\104\040\040\040\040\040\040\040\040\040\144\141\164\141\040\142\171\164\145\050\163\051\040\164\157\040\163\145\156\144\012\012)" with perl command { s/(.*)\n\n/$1/;;$_}.
2020.06.28 11:29:59 5: Postprocessed value is "usage: write [-s QQ] [-d ZZ] -c CIRCUIT NAME [VALUE[;VALUE]*]\n  or:  write [-s QQ] [-d ZZ] -def DEFINITION [VALUE[;VALUE]*] (only if enabled)\n  or:  write [-s QQ] [-c CIRCUIT] -h ZZPBSBNN[DD]*\n Write value(s) or hex message.\n  -s QQ        override source address QQ\n  -d ZZ        override destination address ZZ\n  -c CIRCUIT   CIRCUIT of the message to send\n  NAME         NAME of the message to send\n  VALUE        a single field VALUE\n  -def         write with explicit message definition (only if enabled):\n    DEFINITION message definition to use instead of known definition\n  -h           send hex write message:\n    ZZ         destination address\n    PB SB      primary/secondary command byte\n    NN         number of following data bytes\n    DD         data byte(s) to send (\165\163\141\147\145\072\040\167\162\151\164\145\040\133\055\163\040\121\121\135\040\133\055\144\040\132\132\135\040\055\143\040\103\111\122\103\125\111\124\040\116\101\115\105\040\133\126\101\114\125\105\133\073\126\101\114\125\105\135\052\135\012\040\040\157\162\072\040\040\167\162\151\164\145\040\133\055\163\040\121\121\135\040\133\055\144\040\132\132\135\040\055\144\145\146\040\104\105\106\111\116\111\124\111\117\116\040\133\126\101\114\125\105\133\073\126\101\114\125\105\135\052\135\040\050\157\156\154\171\040\151\146\040\145\156\141\142\154\145\144\051\012\040\040\157\162\072\040\040\167\162\151\164\145\040\133\055\163\040\121\121\135\040\133\055\143\040\103\111\122\103\125\111\124\135\040\055\150\040\132\132\120\102\123\102\116\116\133\104\104\135\052\012\040\127\162\151\164\145\040\166\141\154\165\145\050\163\051\040\157\162\040\150\145\170\040\155\145\163\163\141\147\145\056\012\040\040\055\163\040\121\121\040\040\040\040\040\040\040\040\157\166\145\162\162\151\144\145\040\163\157\165\162\143\145\040\141\144\144\162\145\163\163\040\121\121\012\040\040\055\144\040\132\132\040\040\040\040\040\040\040\040\157\166\145\162\162\151\144\145\040\144\145\163\164\151\156\141\164\151\157\156\040\141\144\144\162\145\163\163\040\132\132\012\040\040\055\143\040\103\111\122\103\125\111\124\040\040\040\103\111\122\103\125\111\124\040\157\146\040\164\150\145\040\155\145\163\163\141\147\145\040\164\157\040\163\145\156\144\012\040\040\116\101\115\105\040\040\040\040\040\040\040\040\040\116\101\115\105\040\157\146\040\164\150\145\040\155\145\163\163\141\147\145\040\164\157\040\163\145\156\144\012\040\040\126\101\114\125\105\040\040\040\040\040\040\040\040\141\040\163\151\156\147\154\145\040\146\151\145\154\144\040\126\101\114\125\105\012\040\040\055\144\145\146\040\040\040\040\040\040\040\040\040\167\162\151\164\145\040\167\151\164\150\040\145\170\160\154\151\143\151\164\040\155\145\163\163\141\147\145\040\144\145\146\151\156\151\164\151\157\156\040\050\157\156\154\171\040\151\146\040\145\156\141\142\154\145\144\051\072\012\040\040\040\040\104\105\106\111\116\111\124\111\117\116\040\155\145\163\163\141\147\145\040\144\145\146\151\156\151\164\151\157\156\040\164\157\040\165\163\145\040\151\156\163\164\145\141\144\040\157\146\040\153\156\157\167\156\040\144\145\146\151\156\151\164\151\157\156\012\040\040\055\150\040\040\040\040\040\040\040\040\040\040\040\163\145\156\144\040\150\145\170\040\167\162\151\164\145\040\155\145\163\163\141\147\145\072\012\040\040\040\040\132\132\040\040\040\040\040\040\040\040\040\144\145\163\164\151\156\141\164\151\157\156\040\141\144\144\162\145\163\163\012\040\040\040\040\120\102\040\123\102\040\040\040\040\040\040\160\162\151\155\141\162\171\057\163\145\143\157\156\144\141\162\171\040\143\157\155\155\141\156\144\040\142\171\164\145\012\040\040\040\040\116\116\040\040\040\040\040\040\040\040\040\156\165\155\142\145\162\040\157\146\040\146\157\154\154\157\167\151\156\147\040\144\141\164\141\040\142\171\164\145\163\012\040\040\040\040\104\104\040\040\040\040\040\040\040\040\040\144\141\164\141\040\142\171\164\145\050\163\051\040\164\157\040\163\145\156\144)".
2020.06.28 11:30:15 1: PERL WARNING: Argument "" isn't numeric in sprintf at (eval 390348) line 1.
2020.06.28 11:30:25 1: PERL WARNING: Argument "" isn't numeric in sprintf at (eval 390375) line 1.
2020.06.28 11:30:34 1: PERL WARNING: Argument "ERR: no signal\n\n" isn't numeric in sprintf at (eval 390396) line 1.
2020.06.28 11:30:34 1: [Freezemon] FreezeMon: possible freeze starting at 11:24:29, delay is 365.752 possibly caused by: tmr-at_Exec(EBUS.Timer) tmr-at_Exec(Klima_addlog)
2020.06.28 11:30:36 5: ECMDDevice: Analyze command >{"w -c recoV Heatrecovery ".ReadingsVal("WTMode_Einstellen","state",0)."\n"}<
2020.06.28 11:30:39 5: Postprocessing "ERR: no signal\n\n (\105\122\122\072\040\156\157\040\163\151\147\156\141\154\012\012)" with perl command { s/(.*)\n\n/$1/;;$_}.
2020.06.28 11:30:39 5: Postprocessed value is "ERR: no signal (\105\122\122\072\040\156\157\040\163\151\147\156\141\154)".
2020.06.28 11:30:45 5: ECMDDevice: Analyze command >{"w -c recoV Heatrecovery ".ReadingsVal("WTMode_Einstellen","state",0)."\n"}<
2020.06.28 11:30:51 5: Postprocessing "empty string" with perl command { s/(.*)\n\n/$1/;;$_}.
2020.06.28 11:30:51 5: Postprocessed value is "empty string".
2020.06.28 11:30:51 2: Automatik_WT:  get WTMode_Soll WTMode_Soll: WTMode_Soll


Dies sind alles Meldungen die mit dem EBUSD zutun haben, davon laufen 2.

systemctl status ebusd1.service
* ebusd1.service - ebusd, the daemon for communication with eBUS heating systems.
   Loaded: loaded (/usr/lib/systemd/system/ebusd1.service; enabled; vendor preset: enabled)
   Active: active (running) since Sat 2020-06-27 17:52:25 CEST; 22h ago
  Process: 1843 ExecStart=/usr/bin/ebusd $EBUSD_OPTS1 (code=exited, status=0/SUCCESS)
Main PID: 1844 (ebusd)
    Tasks: 5 (limit: 4915)
   Memory: 2.0M
   CGroup: /system.slice/ebusd1.service
           `-1844 /usr/bin/ebusd --configpath=/etc/ebusd --enablehex --latency=100000 --receivetimeout=100000 --loglevel=error --scanconfig=08 -d /dev/se

Jun 27 17:52:25 raspberrypi systemd[1]: Starting ebusd, the daemon for communication with eBUS heating systems....
Jun 27 17:52:25 raspberrypi systemd[1]: Started ebusd, the daemon for communication with eBUS heating systems..



systemctl status ebusd2.service
* ebusd2.service - ebusd, the daemon for communication with eBUS heating systems.
   Loaded: loaded (/usr/lib/systemd/system/ebusd2.service; enabled; vendor preset: enabled)
   Active: active (running) since Sat 2020-06-27 17:52:25 CEST; 22h ago
  Process: 556 ExecStart=/usr/bin/ebusd $EBUSD_OPTS2 (code=exited, status=0/SUCCESS)
Main PID: 1844 (ebusd)
    Tasks: 5 (limit: 4915)
   Memory: 3.8M
   CGroup: /system.slice/ebusd2.service
           `-587 /usr/bin/ebusd --configpath=/etc/ebusd --enablehex --latency=100000 --receivetimeout=100000 --loglevel=error -a ff --scanconfig=08 -d /d
           > 1844 /usr/bin/ebusd --configpath=/etc/ebusd --enablehex --latency=100000 --receivetimeout=100000 --loglevel=error --scanconfig=08 -d /dev/se

Jun 27 17:19:24 raspberrypi systemd[1]: Starting ebusd, the daemon for communication with eBUS heating systems....
Jun 27 17:19:24 raspberrypi systemd[1]: ebusd2.service: Can't open PID file /run/ebusd.pid (yet?) after start: No such file or directory
Jun 27 17:52:25 raspberrypi systemd[1]: Started ebusd, the daemon for communication with eBUS heating systems..


OK

also die beiden ebusd1 & ebusd2 gestoppt
systemctl stop ebusd1.service
systemctl stop ebusd2.service

plötzlich geht die Hölle ab  ;D
fhem ist wieder erreichbar und in Telegramm bekomme ich tausende Nachrichten.(1135messages)
EBUS offline
EBUS online
............

also schnell die beiden EBUS-Telegramm DOIF's deaktiviert
Die Nachrichten gehen weiter
Warscheinlich alte NAchrichten die Telegramm jetzt rausschmeisst
Schade das ich Telegramm nicht deaktivieren kann (1586messages)

EGAL

das ist was ich in Verdacht hatte, fhem(Perl) hängt in einer Schleife, hier halt die Warnungen wegen dem EBUSD (3060messages)

so erstmal fhem.service neu starten damit Telegramm aufhört  ;D
bie gleich

MfG Maik
Titel: Antw:fhem freeze nach 2 Minuten oder sporadisch
Beitrag von: TiPpFeHlEr am 28 Juni 2020, 17:02:57
Weiter gehts,,

warum steigt der ebusd nicht aus, ist aber DISCONNECTED und wieder CONNECTED
also mal nach der Hardware geschaut

lsusb
Bus 002 Device 002: ID 0781:5588 SanDisk Corp.
Bus 002 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub
Bus 001 Device 003: ID 04fa:2490 Dallas Semiconductor DS1490F 2-in-1 Fob, 1-Wire                                                                          adapter
Bus 001 Device 002: ID 2109:3431 VIA Labs, Inc. Hub
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub


Hmmm... da fehlt doch was

der aktive USB 2.1 7 Port HUB der am pi hängt, inkl. der beider EBUS-Adapter und dem RXArduino und der Strom.KG serial Adapter & der Tor serial Adatpter

Den USB HUB kpl. getrennt und wieder angesteckt -> keine Reaktion -> HUB startet nicht
pi muss kpl neu gestartet werden -> HUB wird wieder erkannt und alle daran angeschlossenen Geräte auch.

so sollte es eigentlich aussehen

lsusb
Bus 002 Device 002: ID 0781:5588 SanDisk Corp.
Bus 002 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub
Bus 001 Device 004: ID 04fa:2490 Dallas Semiconductor DS1490F 2-in-1 Fob, 1-Wire adapter
Bus 001 Device 011: ID 046d:c52b Logitech, Inc. Unifying Receiver
Bus 001 Device 010: ID 1a86:7523 QinHeng Electronics HL-340 USB-Serial adapter
Bus 001 Device 008: ID 0403:6001 Future Technology Devices International, Ltd FT232 Serial (UART) IC
Bus 001 Device 006: ID 0403:6001 Future Technology Devices International, Ltd FT232 Serial (UART) IC
Bus 001 Device 009: ID 0403:6001 Future Technology Devices International, Ltd FT232 Serial (UART) IC
Bus 001 Device 007: ID 0403:6001 Future Technology Devices International, Ltd FT232 Serial (UART) IC
Bus 001 Device 005: ID 2109:2813 VIA Labs, Inc.
Bus 001 Device 003: ID 1a40:0201 Terminus Technology Inc. FE 2.1 7-port Hub
Bus 001 Device 002: ID 2109:3431 VIA Labs, Inc. Hub
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub


MfG Maik
Titel: Antw:fhem freeze nach 2 Minuten oder sporadisch
Beitrag von: TiPpFeHlEr am 28 Juni 2020, 17:13:38
was sagt uns /var/log/messages dazu?

genau zum Zeitpunkt der letzten Aktion >:(
Jun 28 11:21:14 raspberrypi kernel: [62970.124573] usb 1-1.4.1: USB disconnect, device number 5
Jun 28 11:21:14 raspberrypi kernel: [62970.124581] usb 1-1.4.1.1: USB disconnect, device number 7
Jun 28 11:21:14 raspberrypi kernel: [62970.125580] ftdi_sio ttyUSB1: FTDI USB Serial Device converter now disconnected from ttyUSB1
Jun 28 11:21:14 raspberrypi kernel: [62970.125614] ftdi_sio 1-1.4.1.1:1.0: device disconnected
Jun 28 11:21:14 raspberrypi kernel: [62970.126671] usb 1-1.4.1.2: USB disconnect, device number 9
Jun 28 11:21:14 raspberrypi kernel: [62970.127171] ftdi_sio ttyUSB3: FTDI USB Serial Device converter now disconnected from ttyUSB3
Jun 28 11:21:14 raspberrypi kernel: [62970.127214] ftdi_sio 1-1.4.1.2:1.0: device disconnected
Jun 28 11:21:14 raspberrypi kernel: [62970.129341] usb 1-1.4.2: USB disconnect, device number 6
Jun 28 11:21:14 raspberrypi kernel: [62970.129679] ftdi_sio ttyUSB0: FTDI USB Serial Device converter now disconnected from ttyUSB0
Jun 28 11:21:14 raspberrypi kernel: [62970.129733] ftdi_sio 1-1.4.2:1.0: device disconnected
Jun 28 11:21:14 raspberrypi kernel: [62970.146179] usb 1-1.4.3: USB disconnect, device number 8
Jun 28 11:21:14 raspberrypi kernel: [62970.148485] ftdi_sio ttyUSB2: FTDI USB Serial Device converter now disconnected from ttyUSB2
Jun 28 11:21:14 raspberrypi kernel: [62970.148541] ftdi_sio 1-1.4.3:1.0: device disconnected
Jun 28 11:21:14 raspberrypi kernel: [62970.150279] usb 1-1.4.4: USB disconnect, device number 10
Jun 28 11:21:14 raspberrypi kernel: [62970.151428] ch341-uart ttyUSB4: ch341-uart converter now disconnected from ttyUSB4
Jun 28 11:21:14 raspberrypi kernel: [62970.151463] ch341 1-1.4.4:1.0: device disconnected
Jun 28 11:21:14 raspberrypi kernel: [62970.152442] usb 1-1.4.7: USB disconnect, device number 11
Jun 28 11:21:15 raspberrypi kernel: [62970.460413] usb 1-1.4: reset high-speed USB device number 4 using xhci_hcd
Jun 28 11:21:15 raspberrypi kernel: [62971.010411] usb 1-1.4: reset high-speed USB device number 4 using xhci_hcd
Jun 28 11:21:16 raspberrypi kernel: [62971.550440] usb 1-1.4: reset high-speed USB device number 4 using xhci_hcd
Jun 28 11:21:16 raspberrypi kernel: [62971.550629] usb 1-1.4: Device not responding to setup address.
Jun 28 11:21:16 raspberrypi kernel: [62971.770404] usb 1-1.4: Device not responding to setup address.
Jun 28 11:21:16 raspberrypi kernel: [62972.090211] usb 1-1.4: reset high-speed USB device number 4 using xhci_hcd
Jun 28 11:21:16 raspberrypi kernel: [62972.090413] usb 1-1.4: Device not responding to setup address.
Jun 28 11:21:17 raspberrypi kernel: [62972.310466] usb 1-1.4: Device not responding to setup address.
Jun 28 11:21:17 raspberrypi kernel: [62972.531586] usb 1-1.4: USB disconnect, device number 4
Jun 28 11:21:17 raspberrypi kernel: [62972.750265] usb 1-1.4: new high-speed USB device number 12 using xhci_hcd
Jun 28 11:21:18 raspberrypi kernel: [62973.290195] usb 1-1.4: new high-speed USB device number 13 using xhci_hcd
Jun 28 11:21:18 raspberrypi kernel: [62973.730458] usb 1-1-port4: attempt power cycle
Jun 28 11:21:19 raspberrypi kernel: [62974.400209] usb 1-1.4: new high-speed USB device number 14 using xhci_hcd
Jun 28 11:21:19 raspberrypi kernel: [62974.400390] usb 1-1.4: Device not responding to setup address.
Jun 28 11:21:19 raspberrypi kernel: [62974.620386] usb 1-1.4: Device not responding to setup address.
Jun 28 11:21:19 raspberrypi kernel: [62974.940258] usb 1-1.4: new high-speed USB device number 15 using xhci_hcd
Jun 28 11:21:19 raspberrypi kernel: [62974.940467] usb 1-1.4: Device not responding to setup address.
Jun 28 11:21:19 raspberrypi kernel: [62975.160437] usb 1-1.4: Device not responding to setup address.


im kern.log steht dazu
Jun 28 11:21:09 raspberrypi kernel: [62964.664293] ftdi_sio ttyUSB2: failed to get modem status: -71
Jun 28 11:21:09 raspberrypi kernel: [62964.665870] ftdi_sio ttyUSB2: ftdi_set_termios urb failed to set baudrate
Jun 28 11:21:09 raspberrypi kernel: [62964.667321] ftdi_sio ttyUSB2: failed to set flow control: -71
Jun 28 11:21:09 raspberrypi kernel: [62964.668786] ftdi_sio ttyUSB2: failed to get modem status: -71
Jun 28 11:21:09 raspberrypi kernel: [62964.670109] ftdi_sio ttyUSB2: error from flowcontrol urb
Jun 28 11:21:09 raspberrypi kernel: [62964.691395] ftdi_sio ttyUSB0: failed to get modem status: -71
Jun 28 11:21:09 raspberrypi kernel: [62964.692518] ftdi_sio ttyUSB0: ftdi_set_termios urb failed to set baudrate
Jun 28 11:21:09 raspberrypi kernel: [62964.693750] ftdi_sio ttyUSB0: failed to set flow control: -71
Jun 28 11:21:09 raspberrypi kernel: [62964.694877] ftdi_sio ttyUSB0: failed to get modem status: -71
Jun 28 11:21:09 raspberrypi kernel: [62964.696036] ftdi_sio ttyUSB0: error from flowcontrol urb
Jun 28 11:21:10 raspberrypi kernel: [62965.653825] usb 1-1.4-port7: cannot reset (err = -71)
Jun 28 11:21:10 raspberrypi kernel: [62965.654723] usb 1-1.4-port7: cannot reset (err = -71)
Jun 28 11:21:10 raspberrypi kernel: [62965.655550] usb 1-1.4-port7: cannot reset (err = -71)
Jun 28 11:21:10 raspberrypi kernel: [62965.656472] usb 1-1.4-port7: cannot reset (err = -71)
Jun 28 11:21:10 raspberrypi kernel: [62965.657477] usb 1-1.4-port7: cannot reset (err = -71)
Jun 28 11:21:10 raspberrypi kernel: [62965.657486] usb 1-1.4-port7: Cannot enable. Maybe the USB cable is bad?
Jun 28 11:21:10 raspberrypi kernel: [62965.658264] usb 1-1.4-port7: cannot disable (err = -71)
Jun 28 11:21:10 raspberrypi kernel: [62965.659091] usb 1-1.4-port7: cannot reset (err = -71)
Jun 28 11:21:10 raspberrypi kernel: [62965.659960] usb 1-1.4-port7: cannot reset (err = -71)
Jun 28 11:21:10 raspberrypi kernel: [62965.660970] usb 1-1.4-port7: cannot reset (err = -71)
Jun 28 11:21:10 raspberrypi kernel: [62965.661723] usb 1-1.4-port7: cannot reset (err = -71)
Jun 28 11:21:10 raspberrypi kernel: [62965.662638] usb 1-1.4-port7: cannot reset (err = -71)
Jun 28 11:21:10 raspberrypi kernel: [62965.662647] usb 1-1.4-port7: Cannot enable. Maybe the USB cable is bad?
Jun 28 11:21:10 raspberrypi kernel: [62965.663619] usb 1-1.4-port7: cannot disable (err = -71)
Jun 28 11:21:10 raspberrypi kernel: [62965.664451] usb 1-1.4-port7: cannot reset (err = -71)
Jun 28 11:21:10 raspberrypi kernel: [62965.665351] usb 1-1.4-port7: cannot reset (err = -71)
Jun 28 11:21:10 raspberrypi kernel: [62965.666313] usb 1-1.4-port7: cannot reset (err = -71)
Jun 28 11:21:10 raspberrypi kernel: [62965.667093] usb 1-1.4-port7: cannot reset (err = -71)
Jun 28 11:21:10 raspberrypi kernel: [62965.668081] usb 1-1.4-port7: cannot reset (err = -71)
Jun 28 11:21:10 raspberrypi kernel: [62965.668089] usb 1-1.4-port7: Cannot enable. Maybe the USB cable is bad?
Jun 28 11:21:10 raspberrypi kernel: [62965.668997] usb 1-1.4-port7: cannot disable (err = -71)
Jun 28 11:21:10 raspberrypi kernel: [62965.669836] usb 1-1.4-port7: cannot reset (err = -71)
Jun 28 11:21:10 raspberrypi kernel: [62965.670746] usb 1-1.4-port7: cannot reset (err = -71)
Jun 28 11:21:10 raspberrypi kernel: [62965.671714] usb 1-1.4-port7: cannot reset (err = -71)
Jun 28 11:21:10 raspberrypi kernel: [62965.672509] usb 1-1.4-port7: cannot reset (err = -71)
Jun 28 11:21:10 raspberrypi kernel: [62965.673443] usb 1-1.4-port7: cannot reset (err = -71)
Jun 28 11:21:10 raspberrypi kernel: [62965.673452] usb 1-1.4-port7: Cannot enable. Maybe the USB cable is bad?
Jun 28 11:21:10 raspberrypi kernel: [62965.674447] usb 1-1.4-port7: cannot disable (err = -71)
Jun 28 11:21:10 raspberrypi kernel: [62965.675210] usb 1-1.4-port7: cannot disable (err = -71)
Jun 28 11:21:10 raspberrypi kernel: [62965.676005] hub 1-1.4:1.0: hub_ext_port_status failed (err = -71)
Jun 28 11:21:14 raspberrypi kernel: [62969.674369] ftdi_sio ttyUSB2: ftdi_set_termios FAILED to set databits/stopbits/parity
Jun 28 11:21:14 raspberrypi kernel: [62969.675168] ftdi_sio ttyUSB2: ftdi_set_termios urb failed to set baudrate
Jun 28 11:21:14 raspberrypi kernel: [62969.676234] ftdi_sio ttyUSB2: failed to set flow control: -71
Jun 28 11:21:14 raspberrypi kernel: [62969.678360] ftdi_sio ttyUSB2: Unable to write latency timer: -71
Jun 28 11:21:14 raspberrypi kernel: [62969.679495] ftdi_sio ttyUSB2: failed to get modem status: -71
Jun 28 11:21:14 raspberrypi kernel: [62969.680620] ftdi_sio ttyUSB2: ftdi_set_termios urb failed to set baudrate
Jun 28 11:21:14 raspberrypi kernel: [62969.681651] ftdi_sio ttyUSB2: failed to set flow control: -71
Jun 28 11:21:14 raspberrypi kernel: [62969.682888] ftdi_sio ttyUSB2: failed to get modem status: -71
Jun 28 11:21:14 raspberrypi kernel: [62969.684121] ftdi_sio ttyUSB2: ftdi_set_termios urb failed to set baudrate
Jun 28 11:21:14 raspberrypi kernel: [62969.685234] ftdi_sio ttyUSB2: failed to set flow control: -71
Jun 28 11:21:14 raspberrypi kernel: [62969.686566] ftdi_sio ttyUSB2: failed to get modem status: -71
Jun 28 11:21:14 raspberrypi kernel: [62969.687920] ftdi_sio ttyUSB2: error from flowcontrol urb
Jun 28 11:21:14 raspberrypi kernel: [62969.701304] ftdi_sio ttyUSB0: ftdi_set_termios FAILED to set databits/stopbits/parity
Jun 28 11:21:14 raspberrypi kernel: [62969.702365] ftdi_sio ttyUSB0: ftdi_set_termios urb failed to set baudrate
Jun 28 11:21:14 raspberrypi kernel: [62969.703289] ftdi_sio ttyUSB0: failed to set flow control: -71
Jun 28 11:21:14 raspberrypi kernel: [62969.705940] ftdi_sio ttyUSB0: Unable to write latency timer: -71
Jun 28 11:21:14 raspberrypi kernel: [62969.707380] ftdi_sio ttyUSB0: failed to get modem status: -71
Jun 28 11:21:14 raspberrypi kernel: [62969.708686] ftdi_sio ttyUSB0: ftdi_set_termios urb failed to set baudrate
Jun 28 11:21:14 raspberrypi kernel: [62969.709884] ftdi_sio ttyUSB0: failed to set flow control: -71
Jun 28 11:21:14 raspberrypi kernel: [62969.711273] ftdi_sio ttyUSB0: failed to get modem status: -71
Jun 28 11:21:14 raspberrypi kernel: [62969.712295] ftdi_sio ttyUSB0: ftdi_set_termios urb failed to set baudrate
Jun 28 11:21:14 raspberrypi kernel: [62969.713624] ftdi_sio ttyUSB0: failed to set flow control: -71
Jun 28 11:21:14 raspberrypi kernel: [62969.715049] ftdi_sio ttyUSB0: failed to get modem status: -71
Jun 28 11:21:14 raspberrypi kernel: [62969.716386] ftdi_sio ttyUSB0: error from flowcontrol urb
Jun 28 11:21:14 raspberrypi kernel: [62970.124573] usb 1-1.4.1: USB disconnect, device number 5
Jun 28 11:21:14 raspberrypi kernel: [62970.124581] usb 1-1.4.1.1: USB disconnect, device number 7
Jun 28 11:21:14 raspberrypi kernel: [62970.125361] ftdi_sio ttyUSB1: error from flowcontrol urb
Jun 28 11:21:14 raspberrypi kernel: [62970.125580] ftdi_sio ttyUSB1: FTDI USB Serial Device converter now disconnected from ttyUSB1
Jun 28 11:21:14 raspberrypi kernel: [62970.125614] ftdi_sio 1-1.4.1.1:1.0: device disconnected
Jun 28 11:21:14 raspberrypi kernel: [62970.126671] usb 1-1.4.1.2: USB disconnect, device number 9
Jun 28 11:21:14 raspberrypi kernel: [62970.126903] ftdi_sio ttyUSB3: error from flowcontrol urb
Jun 28 11:21:14 raspberrypi kernel: [62970.127171] ftdi_sio ttyUSB3: FTDI USB Serial Device converter now disconnected from ttyUSB3
Jun 28 11:21:14 raspberrypi kernel: [62970.127214] ftdi_sio 1-1.4.1.2:1.0: device disconnected
Jun 28 11:21:14 raspberrypi kernel: [62970.129341] usb 1-1.4.2: USB disconnect, device number 6
Jun 28 11:21:14 raspberrypi kernel: [62970.129679] ftdi_sio ttyUSB0: FTDI USB Serial Device converter now disconnected from ttyUSB0
Jun 28 11:21:14 raspberrypi kernel: [62970.129733] ftdi_sio 1-1.4.2:1.0: device disconnected
Jun 28 11:21:14 raspberrypi kernel: [62970.146179] usb 1-1.4.3: USB disconnect, device number 8
Jun 28 11:21:14 raspberrypi kernel: [62970.148485] ftdi_sio ttyUSB2: FTDI USB Serial Device converter now disconnected from ttyUSB2
Jun 28 11:21:14 raspberrypi kernel: [62970.148541] ftdi_sio 1-1.4.3:1.0: device disconnected
Jun 28 11:21:14 raspberrypi kernel: [62970.150279] usb 1-1.4.4: USB disconnect, device number 10
Jun 28 11:21:14 raspberrypi kernel: [62970.151180] usb 1-1.4.4: failed to send control message: -19
Jun 28 11:21:14 raspberrypi kernel: [62970.151428] ch341-uart ttyUSB4: ch341-uart converter now disconnected from ttyUSB4
Jun 28 11:21:14 raspberrypi kernel: [62970.151463] ch341 1-1.4.4:1.0: device disconnected
Jun 28 11:21:14 raspberrypi kernel: [62970.152442] usb 1-1.4.7: USB disconnect, device number 11
Jun 28 11:21:15 raspberrypi kernel: [62970.460413] usb 1-1.4: reset high-speed USB device number 4 using xhci_hcd
Jun 28 11:21:15 raspberrypi kernel: [62970.560442] usb 1-1.4: device descriptor read/64, error -71
Jun 28 11:21:15 raspberrypi kernel: [62970.790383] usb 1-1.4: device descriptor read/64, error -71
Jun 28 11:21:15 raspberrypi kernel: [62971.010411] usb 1-1.4: reset high-speed USB device number 4 using xhci_hcd
Jun 28 11:21:15 raspberrypi kernel: [62971.110409] usb 1-1.4: device descriptor read/64, error -71
Jun 28 11:21:16 raspberrypi kernel: [62971.330412] usb 1-1.4: device descriptor read/64, error -71
Jun 28 11:21:16 raspberrypi kernel: [62971.550440] usb 1-1.4: reset high-speed USB device number 4 using xhci_hcd
Jun 28 11:21:16 raspberrypi kernel: [62971.550629] usb 1-1.4: Device not responding to setup address.
Jun 28 11:21:16 raspberrypi kernel: [62971.770404] usb 1-1.4: Device not responding to setup address.
Jun 28 11:21:16 raspberrypi kernel: [62971.990201] usb 1-1.4: device not accepting address 4, error -71
Jun 28 11:21:16 raspberrypi kernel: [62972.090211] usb 1-1.4: reset high-speed USB device number 4 using xhci_hcd
Jun 28 11:21:16 raspberrypi kernel: [62972.090413] usb 1-1.4: Device not responding to setup address.
Jun 28 11:21:17 raspberrypi kernel: [62972.310466] usb 1-1.4: Device not responding to setup address.
Jun 28 11:21:17 raspberrypi kernel: [62972.530220] usb 1-1.4: device not accepting address 4, error -71
Jun 28 11:21:17 raspberrypi kernel: [62972.531586] usb 1-1.4: USB disconnect, device number 4
Jun 28 11:21:17 raspberrypi kernel: [62972.750265] usb 1-1.4: new high-speed USB device number 12 using xhci_hcd
Jun 28 11:21:17 raspberrypi kernel: [62972.850396] usb 1-1.4: device descriptor read/64, error -71
Jun 28 11:21:17 raspberrypi kernel: [62973.070365] usb 1-1.4: device descriptor read/64, error -71
Jun 28 11:21:18 raspberrypi kernel: [62973.290195] usb 1-1.4: new high-speed USB device number 13 using xhci_hcd
Jun 28 11:21:18 raspberrypi kernel: [62973.390403] usb 1-1.4: device descriptor read/64, error -71
Jun 28 11:21:18 raspberrypi kernel: [62973.610462] usb 1-1.4: device descriptor read/64, error -71
Jun 28 11:21:18 raspberrypi kernel: [62973.730458] usb 1-1-port4: attempt power cycle
Jun 28 11:21:19 raspberrypi kernel: [62974.400209] usb 1-1.4: new high-speed USB device number 14 using xhci_hcd
Jun 28 11:21:19 raspberrypi kernel: [62974.400390] usb 1-1.4: Device not responding to setup address.
Jun 28 11:21:19 raspberrypi kernel: [62974.620386] usb 1-1.4: Device not responding to setup address.
Jun 28 11:21:19 raspberrypi kernel: [62974.840248] usb 1-1.4: device not accepting address 14, error -71
Jun 28 11:21:19 raspberrypi kernel: [62974.940258] usb 1-1.4: new high-speed USB device number 15 using xhci_hcd
Jun 28 11:21:19 raspberrypi kernel: [62974.940467] usb 1-1.4: Device not responding to setup address.
Jun 28 11:21:19 raspberrypi kernel: [62975.160437] usb 1-1.4: Device not responding to setup address.
Jun 28 11:21:20 raspberrypi kernel: [62975.380257] usb 1-1.4: device not accepting address 15, error -71
Jun 28 11:21:20 raspberrypi kernel: [62975.380536] usb 1-1-port4: unable to enumerate USB device


und einige Zeit später im messages
Jun 28 16:58:48 raspberrypi kernel: [83224.300765] usb 1-1.4: new high-speed USB device number 16 using xhci_hcd
Jun 28 16:58:49 raspberrypi kernel: [83224.840786] usb 1-1.4: new high-speed USB device number 17 using xhci_hcd
Jun 28 16:58:49 raspberrypi kernel: [83225.301128] usb 1-1-port4: attempt power cycle
Jun 28 16:58:50 raspberrypi kernel: [83225.960790] usb 1-1.4: new high-speed USB device number 18 using xhci_hcd
Jun 28 16:58:50 raspberrypi kernel: [83225.960998] usb 1-1.4: Device not responding to setup address.
Jun 28 16:58:50 raspberrypi kernel: [83226.180963] usb 1-1.4: Device not responding to setup address.
Jun 28 16:58:50 raspberrypi kernel: [83226.500801] usb 1-1.4: new high-speed USB device number 19 using xhci_hcd
Jun 28 16:58:50 raspberrypi kernel: [83226.501011] usb 1-1.4: Device not responding to setup address.
Jun 28 16:58:51 raspberrypi kernel: [83226.721010] usb 1-1.4: Device not responding to setup address.
Jun 28 16:59:21 raspberrypi kernel: [83256.811280] usb 1-1.1: new high-speed USB device number 20 using xhci_hcd
Jun 28 16:59:21 raspberrypi kernel: [83257.351297] usb 1-1.1: new high-speed USB device number 21 using xhci_hcd
Jun 28 16:59:22 raspberrypi kernel: [83257.791607] usb 1-1-port1: attempt power cycle
Jun 28 16:59:22 raspberrypi kernel: [83258.451303] usb 1-1.1: new high-speed USB device number 22 using xhci_hcd
Jun 28 16:59:22 raspberrypi kernel: [83258.451513] usb 1-1.1: Device not responding to setup address.
Jun 28 16:59:23 raspberrypi kernel: [83258.671473] usb 1-1.1: Device not responding to setup address.
Jun 28 16:59:23 raspberrypi kernel: [83258.991314] usb 1-1.1: new high-speed USB device number 23 using xhci_hcd
Jun 28 16:59:23 raspberrypi kernel: [83258.991514] usb 1-1.1: Device not responding to setup address.
Jun 28 16:59:23 raspberrypi kernel: [83259.211492] usb 1-1.1: Device not responding to setup address.

und kern.log
Jun 28 16:58:48 raspberrypi kernel: [83224.300765] usb 1-1.4: new high-speed USB device number 16 using xhci_hcd
Jun 28 16:58:48 raspberrypi kernel: [83224.400983] usb 1-1.4: device descriptor read/64, error -71
Jun 28 16:58:49 raspberrypi kernel: [83224.620973] usb 1-1.4: device descriptor read/64, error -71
Jun 28 16:58:49 raspberrypi kernel: [83224.840786] usb 1-1.4: new high-speed USB device number 17 using xhci_hcd
Jun 28 16:58:49 raspberrypi kernel: [83224.951019] usb 1-1.4: device descriptor read/64, error -71
Jun 28 16:58:49 raspberrypi kernel: [83225.171002] usb 1-1.4: device descriptor read/64, error -71
Jun 28 16:58:49 raspberrypi kernel: [83225.301128] usb 1-1-port4: attempt power cycle
Jun 28 16:58:50 raspberrypi kernel: [83225.960790] usb 1-1.4: new high-speed USB device number 18 using xhci_hcd
Jun 28 16:58:50 raspberrypi kernel: [83225.960998] usb 1-1.4: Device not responding to setup address.
Jun 28 16:58:50 raspberrypi kernel: [83226.180963] usb 1-1.4: Device not responding to setup address.
Jun 28 16:58:50 raspberrypi kernel: [83226.400793] usb 1-1.4: device not accepting address 18, error -71
Jun 28 16:58:50 raspberrypi kernel: [83226.500801] usb 1-1.4: new high-speed USB device number 19 using xhci_hcd
Jun 28 16:58:50 raspberrypi kernel: [83226.501011] usb 1-1.4: Device not responding to setup address.
Jun 28 16:58:51 raspberrypi kernel: [83226.721010] usb 1-1.4: Device not responding to setup address.
Jun 28 16:58:51 raspberrypi kernel: [83226.940804] usb 1-1.4: device not accepting address 19, error -71
Jun 28 16:58:51 raspberrypi kernel: [83226.941053] usb 1-1-port4: unable to enumerate USB device
Jun 28 16:59:21 raspberrypi kernel: [83256.811280] usb 1-1.1: new high-speed USB device number 20 using xhci_hcd
Jun 28 16:59:21 raspberrypi kernel: [83256.911502] usb 1-1.1: device descriptor read/64, error -71
Jun 28 16:59:21 raspberrypi kernel: [83257.131490] usb 1-1.1: device descriptor read/64, error -71
Jun 28 16:59:21 raspberrypi kernel: [83257.351297] usb 1-1.1: new high-speed USB device number 21 using xhci_hcd
Jun 28 16:59:21 raspberrypi kernel: [83257.451496] usb 1-1.1: device descriptor read/64, error -71
Jun 28 16:59:22 raspberrypi kernel: [83257.671506] usb 1-1.1: device descriptor read/64, error -71
Jun 28 16:59:22 raspberrypi kernel: [83257.791607] usb 1-1-port1: attempt power cycle
Jun 28 16:59:22 raspberrypi kernel: [83258.451303] usb 1-1.1: new high-speed USB device number 22 using xhci_hcd
Jun 28 16:59:22 raspberrypi kernel: [83258.451513] usb 1-1.1: Device not responding to setup address.
Jun 28 16:59:23 raspberrypi kernel: [83258.671473] usb 1-1.1: Device not responding to setup address.
Jun 28 16:59:23 raspberrypi kernel: [83258.891318] usb 1-1.1: device not accepting address 22, error -71
Jun 28 16:59:23 raspberrypi kernel: [83258.991314] usb 1-1.1: new high-speed USB device number 23 using xhci_hcd
Jun 28 16:59:23 raspberrypi kernel: [83258.991514] usb 1-1.1: Device not responding to setup address.
Jun 28 16:59:23 raspberrypi kernel: [83259.211492] usb 1-1.1: Device not responding to setup address.
Jun 28 16:59:23 raspberrypi kernel: [83259.431327] usb 1-1.1: device not accepting address 23, error -71
Jun 28 16:59:23 raspberrypi kernel: [83259.431677] usb 1-1-port1: unable to enumerate USB device


geil iss die Aussage vom Kernel
Cannot enable. Maybe the USB cable is bad? OK
Challange accepted ;D

MfG Maik
Titel: Antw:fhem freeze nach 2 Minuten oder sporadisch
Beitrag von: Wernieman am 28 Juni 2020, 17:57:29
WAS für ein PI4 ist es?

Ich glaube, Du hast die Version 1 mit dem bekannten USB-Bug .... bzw. ein generelles USB-Problem ..... (Deshalb bitte keine SSD verwenden!)

Man darf nicht vergessen, das FHEM im Grunde (abgesehen von speziellen Modulen) single Threaded ist. Wenn also eine Aktion auf irgendetwas "wartet", tut FHEM eben nichts, auch nicht auf WEB reagieren .....
Titel: Antw:fhem freeze nach 2 Minuten oder sporadisch
Beitrag von: TiPpFeHlEr am 28 Juni 2020, 19:26:09
Zitat von: Wernieman am 28 Juni 2020, 17:57:29
WAS für ein PI4 ist es?

Ich glaube, Du hast die Version 1 mit dem bekannten USB-Bug .... bzw. ein generelles USB-Problem ..... (Deshalb bitte keine SSD verwenden!)

Man darf nicht vergessen, das FHEM im Grunde (abgesehen von speziellen Modulen) single Threaded ist. Wenn also eine Aktion auf irgendetwas "wartet", tut FHEM eben nichts, auch nicht auf WEB reagieren .....

Raspberry Pi 4 Model B Rev 1.2

Der BUG betrifft aber den USB-C, da gehts um Spannungsversorgung bei intelligenten Netzteilen.
Ich scheine ein USB-HUB Problem zu haben.
Da hast du Recht da wäre ne USB SSD nicht sinnvoll!

Gibts ne Möglichkeit bei ECMD irgendwie darauf zu reagieren wenn die Hardware nicht verfügbar ist?
Als erstes habe ich meine DOIF's abgeschaltet die mir den Zustand der EBUS Adapter mitteilen.

MfG Maik
Titel: Antw:fhem freeze nach 2 Minuten oder sporadisch
Beitrag von: Wernieman am 28 Juni 2020, 20:03:36
Ich muß gestehen, das ich das Problem anderes angehen würde:

1. Server und Anzeige trennen. Du hast bei Dir beides auf einer Hardware laufen
2. Bessere Hardware für FHEM nehmen ....  der Pi ist für vieles Gut, aber für ein kritisches Hausautomatisationssystem ist er mir dann doch .... da ist eine x86-System wie z.B. ZOTAC (oder wenn es sein muß Intel NUC) dann doch optimaler. Und der Stromverbrauch ist (z.B. bei meinem System mit 7W incl. Zusätzlichem USB3-Hub) gegenüber einem Pi auch nicht sooo viel Größer.
3. Den Pi dann nur noch als Anzeige ....

Wenn Du die bis jetzt invertierte Zeit rechnest, ist der Pi auch nicht günstiger als eine "bessere" Hardware. Damit will ich den Pi nicht schlechtmachen. Verwende Ihn  hier z.B. als Ansteuerplatform von USB-Schaltsteckdosen (Die mir immer den USB-Bus gestört haben) und als kleine "Firewall", d.h. für die Anfragen aus dem Netz. In der Firma laufen die Monitoringsysteme, also die Geräte, welche das Monitoring auf Bildschirmen anzeigen, mit Pis. Da interessiert es auch wenig, wenn es mal einen Pi erwischt (siehe Beitrag hier im Forum). Aber für ein wichtiges 24*7-System würde ich Ihn nicht mehr nehmen.
Titel: Antw:fhem freeze nach 2 Minuten oder sporadisch
Beitrag von: feger am 28 Juni 2020, 22:45:24
Hast du vielleicht eine Möglichkeit die Netzteil Spannung zu messen? (im Betrieb)
Vielleicht kann der Pi es selbst?

Wenn die Versorgungsspannung zu niedrig ist und du auch noch so viele USB Geräte ansteckst, vielleicht dreht er dann den USB ab?

Habe schon öfters gelesen das er mit manchen aktiven USB Hubs Probleme hat.
Funktioniert der Hub am PC?

mfg Feger
Titel: Antw:fhem freeze nach 2 Minuten oder sporadisch
Beitrag von: mumpitzstuff am 28 Juni 2020, 23:23:44
Solche Fehler hatte ich auch und sie haben mich fast zur Verzweiflung getrieben. Die PIs haben 3 grundsätzliche Probleme.

1.) Sie funktionieren nur mit sehr wenigen HUBs zusammen.
2.) Sie funktionieren nur mit wenigen externen USB Gehäusen zusammen.
3.) Niemand kann einem wirklich sagen was wirklich wie zusammen funktioniert.

Nach viel probieren läuft jetzt folgendes stabil:

D-Link DUB-1340 (USB 3.0 HUB)
Ugreen Festplattengehäuse mit der Modellnummer 60353 (auf Amazon ugreen 60353 suchen)

Ohne aktiv versorgten HUB habe ich übrigens nur noch instabile Systeme gehabt...
Manche Festplattengehäuse kann man mittels Kompatibilitätsmodus dazu bringen zu funktionieren, das war aber bei mir auch nur halblebig.

Bei mir waren es am Ende die Festplattengehäuse die das Problem verursacht hatten und nicht der HUB. Ich würde das als erstes tauschen. Ich hatte vorher leider 3 HUBs ausprobiert, was richtig Geld gekostet hat.


Titel: Antw:fhem freeze nach 2 Minuten oder sporadisch
Beitrag von: TiPpFeHlEr am 29 Juni 2020, 12:30:14
Hi @ all

1. Ich verwende nur extern versorgte HUBs
2.die Spannungen am pi werden mit A/D Wandler kontinuierlich gemessen und geloggt (3.3 & 5 V)
sind beide stabil
3.3 = 3.4V
5.0 = 5.2V
3. X86 System, das ist dann wohl der sicherste Weg.
4. Der USB Stick ist nur für die log, um sie aus / rauszunehmen.
Ich erstelle jede Woche ein Backup der sd Karte, diese ist nur 8gb.
Also müssen die logs ausgelagert sein.
Ansonsten hängt am USB nur kleinkram
2x arduino nano seriell
1x wemos seriell
2x ftdi seriell
2x ebus koppler seriell
Dafür nen funktionierenden hub zu finden hatte ich nicht für problematisch gehalten.
Muss mich jetzt aber eines besseren belehren lassen.
Am pi3b+ hatte ich nicht so dramatische Probleme.

Zurück zum Thema

Warum hing aber fhem nur weil usb Gerät weg war, das gab's früher schon.
Dafür hatte ich ja die DOIFs um es mir zu melden wenn ein USB Gerät nicht mehr funktioniert.

Ich denke eher das es an einer der perl warnungen liegt die da zu sehen sind.


Ich werde das mal versuchen zu reproduzieren.

Mfg Maik


Titel: Antw:fhem freeze nach 2 Minuten oder sporadisch
Beitrag von: Wernieman am 29 Juni 2020, 13:01:32
Habe es hier bei meinem Normalen" System auch so. Eine Platte will in einem USB-Gehäuse (Weiß nicht ob es an Platte oder Gehäuse liegt) nicht am USB 3 HUB. Problemlos erst, als ich einen 2er HUB dazwischengeschaltet habe. Komischerweise habe ich von dem Gehäuse 3 .. die beiden anderen funktionieren Problemlos an USB 3