FHEM neu aufgesetzt - Load > 5

valvak · 13 Mai 2020, 14:39:06

Hallo zusammen

ich hab meinen Raspberry nach knapp 3 Jahren wegen besserem Verständnis neu aufgesetzt (damals mit NOOB und SD-Backups lassen sich nicht shrinken)

Das System habe ich soweit am laufen und alle Module sind installiert. Das Backup kam aus der ConfigDB.

Ich habe das alte System noch mit init.d/fhem gestartet, das neue systemd kenn ich noch nicht 100%ig, habe die Datei aber angepasst.

Allerdings hab ich das Problem das FHEM mehrmals startet und den Load ins unermessliche treibt. Wenn ich Fhem stoppe läuft der Raspi bei <0,2 obwohl Mosquitto, Mysql, Nginx etc. laufen.

Woran kann das liegen? ich hab 1:1 die selbe Konfig. Ich weiss auch nicht welche Codesnippet ich euch zeigen kann

Code Auswählen

pi@raspHOME:~ $ ps axf | grep [f]hem
 8033 pts/0    S+     0:00  |           \_ sudo nano log/fhem-2020-05-13.log
 8041 pts/0    S+     0:01  |               \_ nano log/fhem-2020-05-13.log
 8842 ?        S      1:22 /usr/bin/perl fhem.pl configDB
 8958 ?        Sl     0:03  \_ node /usr/bin/alexa-fhem -c ./alexa-fhem.cfg -a xx:xx -s
 9076 ?        S      0:00  |   \_ /usr/bin/ssh -R 1234:127.0.0.1:39779 -oServerAliveInterval=90 -i /opt/fhem/.ssh/id_rsa -p 58824 fhem-va.fhem.de
 8991 ?        Sl     0:14  \_ /usr/bin/perl ./FHEM/00_SONOS.pm 4711 1 0 startedbyfhem
 9014 ?        S      0:02  \_ /usr/bin/perl fhem.pl configDB
 9407 ?        S      0:00  \_ /usr/bin/perl fhem.pl configDB
 9408 ?        S      0:00  \_ /usr/bin/perl fhem.pl configDB
 9409 ?        S      0:00  \_ /usr/bin/perl fhem.pl configDB
 9410 ?        S      0:00  \_ /usr/bin/perl fhem.pl configDB
 9411 ?        S      0:00  \_ /usr/bin/perl fhem.pl configDB
 9413 ?        S      0:00  \_ /usr/bin/perl fhem.pl configDB
 9414 ?        S      0:00  \_ /usr/bin/perl fhem.pl configDB
 9415 ?        S      0:00  \_ /usr/bin/perl fhem.pl configDB
 9416 ?        S      0:00  \_ /usr/bin/perl fhem.pl configDB
 9417 ?        S      0:00  \_ /usr/bin/perl fhem.pl configDB

Code Auswählen

# $Id: fhem.service 19235 2019-04-21 13:26:17Z betateilchen $

[Unit]
Description=FHEM Home Automation
Wants=network.target
After=network.target
#Requires=postgresql.service
#After=postgresql.service
Requires=mysql.service
After=mysql.service

[Service]
Type=forking
User=fhem
Group=dialout
WorkingDirectory=/opt/fhem
#ExecStart=/usr/bin/perl fhem.pl fhem.cfg
ExecStart=/usr/bin/perl fhem.pl configDB
#Restart=always
Restart=on-failure
RestartSec=15

[Install]
WantedBy=multi-user.target

Code Auswählen

top - 14:38:18 up  1:57,  2 users,  load average: 5,93, 6,06, 4,28
Tasks: 147 total,   1 running, 146 sleeping,   0 stopped,   0 zombie
%Cpu(s):  1,1 us,  1,6 sy,  0,0 ni, 25,4 id, 71,8 wa,  0,0 hi,  0,0 si,  0,0 st
MiB Mem :    926,1 total,    139,6 free,    613,0 used,    173,5 buff/cache
MiB Swap:     25,0 total,      0,0 free,     25,0 used.    245,8 avail Mem

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU  %MEM     TIME+ COMMAND
  627 root      20   0   37968  10184   3708 S   3,3   1,1   3:36.55 lepresenced
  160 root      20   0       0      0      0 S   2,3   0,0   1:00.79 w1_bus_master1
 8991 fhem      20   0   98756  54372   4544 S   1,3   5,7   0:24.19 perl
 9622 pi        20   0   10304   3052   2532 R   1,3   0,3   0:01.44 top
  534 root      20   0  372336 163372   3904 S   0,7  17,2   1:31.63 collectord
  925 root      20   0    2368   1316   1228 S   0,7   0,1   0:33.14 hcidump
   76 root      20   0       0      0      0 D   0,3   0,0   0:00.75 jbd2/mmcblk0p2-
  118 root      20   0   41432  10376   9460 S   0,3   1,1   0:12.75 systemd-journal
  437 root      20   0   27656   1408   1320 S   0,3   0,1   0:12.38 rngd
  822 pi        20   0  113440  50972  26876 S   0,3   5,4   0:21.06 homebridge
  923 root      20   0    2496   1384   1272 S   0,3   0,1   0:21.20 hcitool
 2404 mysql     20   0  616084  92932   6436 S   0,3   9,8   0:32.49 mysqld
 4061 pi        20   0   12236   3560   2800 S   0,3   0,4   0:05.51 sshd
    1 root      20   0   34872   6700   5324 S   0,0   0,7   0:28.86 systemd
    2 root      20   0       0      0      0 S   0,0   0,0   0:00.02 kthreadd
    3 root       0 -20       0      0      0 I   0,0   0,0   0:00.00 rcu_gp
    4 root       0 -20       0      0      0 I   0,0   0,0   0:00.00 rcu_par_gp
    8 root       0 -20       0      0      0 I   0,0   0,0   0:00.00 mm_percpu_wq
    9 root      20   0       0      0      0 S   0,0   0,0   0:01.49 ksoftirqd/0
   10 root      20   0       0      0      0 I   0,0   0,0   0:07.26 rcu_sched
   11 root      20   0       0      0      0 I   0,0   0,0   0:00.00 rcu_bh
   12 root      rt   0       0      0      0 S   0,0   0,0   0:00.08 migration/0
   13 root      20   0       0      0      0 S   0,0   0,0   0:00.00 cpuhp/0
   14 root      20   0       0      0      0 S   0,0   0,0   0:00.00 cpuhp/1

ich hab keine Ahnung ob man da was sieht...
weiß auch gerade nicht weiter.

valvak · 13 Mai 2020, 14:50:03

Code Auswählen

● fhem.service - FHEM Home Automation
   Loaded: loaded (/etc/systemd/system/fhem.service; enabled; vendor preset: enabled)
   Active: active (running) since Wed 2020-05-13 14:47:16 CEST; 1min 5s ago
  Process: 10193 ExecStart=/usr/bin/perl fhem.pl configDB (code=exited, status=0/SUCCESS)
 Main PID: 10196 (perl)
    Tasks: 32 (limit: 2200)
   Memory: 337.3M
   CGroup: /system.slice/fhem.service
           ├─10196 /usr/bin/perl fhem.pl configDB
           ├─10502 node /usr/bin/alexa-fhem -c ./alexa-fhem.cfg -a xx:xx -s
           ├─10549 /usr/bin/perl fhem.pl configDB
           ├─10550 /usr/bin/perl ./FHEM/00_SONOS.pm 4711 1 0 startedbyfhem
           ├─10551 /usr/bin/perl fhem.pl configDB
           ├─10552 /usr/bin/perl fhem.pl configDB
           ├─10555 /usr/bin/perl fhem.pl configDB
           ├─10556 /usr/bin/perl fhem.pl configDB
           ├─10557 /usr/bin/perl fhem.pl configDB
           ├─10558 /usr/bin/perl fhem.pl configDB
           ├─10560 /usr/bin/perl fhem.pl configDB
           ├─10561 /usr/bin/perl fhem.pl configDB
           ├─10562 /usr/bin/perl fhem.pl configDB
           ├─10563 /usr/bin/perl fhem.pl configDB
           ├─10564 /usr/bin/perl fhem.pl configDB
           ├─10565 /usr/bin/perl fhem.pl configDB
           ├─10566 /usr/bin/perl fhem.pl configDB
           ├─10567 /usr/bin/perl fhem.pl configDB
           ├─10568 /usr/bin/perl fhem.pl configDB
           ├─10569 /usr/bin/perl fhem.pl configDB
           ├─10570 /usr/bin/perl fhem.pl configDB
           ├─10571 /usr/bin/perl fhem.pl configDB

Hier auch nochmal die Systemctl Status

Otto123 · 13 Mai 2020, 15:51:32

Hi,

kommentier doch mal bitte die beiden Zeilen aus

Code Auswählen

Restart=on-failure
RestartSec=15

Gruß Otto

valvak · 13 Mai 2020, 15:54:17

das hatte ich schon

gleicher Effekt.

Code Auswählen


#Restart=always
Restart=on-failure
RestartSec=15

die letzten beiden Zeilen sind aus der Not entstanden. ich hatte bereits Restart aktiv (wie in der Standard-Version) und halt auskommentiert ohne die beiden letzten Zeilen.
Ich weiss echt nicht woher dieses Verhalten kommt.

Eine leere ConfigDB läuft mit nur einem Prozess, um es weiter einzugrenzen

Otto123 · 13 Mai 2020, 16:00:57

Ich kenn mich mit configDb nicht aus.
Startet wirklich Dein FHEM immer wieder neu? Oder sind das nur Prozesse von FHEM die abgesetzt werden?
Der zweite Start muss ja in die Hose gehen und dazu muss es einen Eintrag im Log geben.

Gruß Otto

valvak · 13 Mai 2020, 16:04:38

also wenn ich Fhem über

Code Auswählen

perl fhem.pl configDB

starte sehe ich dass wirklich alles doppelt und dreifach startet. In den Logs selber seh ich das aber nicht. Ich kenne mich dafür zu wenig aus um zu sehen was genau das bewirkt.

Ich meine ich bin zwar schon lange mit ubuntu/Debian/Raspbian zugange aber nur auf der Ebene wo es läuft

Fehler Diagnose kenn ich nicht :/

Otto123 · 13 Mai 2020, 16:09:59

poste mal einen Teil der Ausgabe wo Du siehst das es mehrfach startet.

valvak · 13 Mai 2020, 16:11:50

wie genau mach ich das am besten?

das geht so schnell, dass ich es mit STRG-C nicht rausbekomme. Ich weiss das es dieses Tail gibt, aber kann ich das in dem fall nutzen?

valvak · 13 Mai 2020, 16:17:53

ok das hier kann ich noch anbieten. Hab ich auf der Fehler-Such-Wiki gefunden

Code Auswählen


pi@raspHOME:~ $ tail -n 20 /opt/fhem/log/fhem-$(date '+%Y-%m').log
2020.05.13 14:17:58 3: Probing CUL device /dev/ttyACM0
2020.05.13 14:17:58 3: Probing TCM_ESP3 device /dev/ttyACM0
2020.05.13 14:17:58 3: Probing ZWDongle device /dev/ttyACM0
2020.05.13 14:17:58 3: Probing SIGNALDuino device /dev/ttyACM0
2020.05.13 14:17:58 3: Probing MYSENSORS device /dev/ttyACM0
2020.05.13 14:17:58 3: Probing ArduCounter device /dev/ttyACM0
2020.05.13 14:17:59 3: Probing ElsnerWS device /dev/ttyACM0
2020.05.13 14:18:00 3: Probing FRM device /dev/ttyACM0
2020.05.13 14:18:05 3: Probing CUL device /dev/ttyAMA0
2020.05.13 14:18:05 3: Probing TCM_ESP3 device /dev/ttyAMA0
2020.05.13 14:18:05 3: Probing ZWDongle device /dev/ttyAMA0
2020.05.13 14:18:05 3: Probing SIGNALDuino device /dev/ttyAMA0
2020.05.13 14:18:05 3: Probing MYSENSORS device /dev/ttyAMA0
2020.05.13 14:18:06 3: Probing ArduCounter device /dev/ttyAMA0
2020.05.13 14:18:06 3: Probing ElsnerWS device /dev/ttyAMA0
2020.05.13 14:18:07 3: Probing FRM device /dev/ttyAMA0
2020.05.13 14:18:12 1: usb create end
2020.05.13 14:18:12 0: Featurelevel: 6
2020.05.13 14:18:12 0: Server started with 6 defined entities (fhem.pl:21916/2020-05-11 perl:5.028001 os:lin                           ux user:fhem pid:8541)
2020.05.13 14:23:54 0: Server shutdown

Es ist eigenartig das ich im log selber aber Einträge bis jetzt sehe.

valvak · 13 Mai 2020, 16:30:33

So das ist ein kompletter Startvorgang. Ich sehe darin halt nicht diese vielen Starts oder was genau ihn stört.

Code Auswählen

2020.05.13 16:23:41 3: telnetPort: port 7072 opened
2020.05.13 16:23:41 3: WEB: port 8083 opened
2020.05.13 16:23:42 2: eventTypes: loaded 6382 events from ./log/eventTypes.txt
2020.05.13 16:23:42 2: FRITZBOX FritzBox: Define.254 Modul functionality limited because of missing perl modules: Net::Telnet 
2020.05.13 16:23:44 3: TABLETUI: new ext defined infix:ftui/: dir:./www/tablet:
2020.05.13 16:23:44 3: Registering HTTPSRV TABLETUI for URL /ftui   and assigned link ftui/ ...
2020.05.13 16:23:44 3: [Twilight] got no weather info from yahoo. Error code: http://query.yahooapis.com/v1/public/yql?q=select%20*%20from%20weather.forecast%20where%20woeid=0%20and%20u=%27c%27&format=json&env=store%3A%2F%2Fdatatables.org%2Falltableswithkeys: Can't connect(1) to http://query.yahooapis.com:80: IO::Socket::INET: Bad hostname 'query.yahooapis.com:80'
2020.05.13 16:23:51 3: THEIZUNG: port 8086 opened
2020.05.13 16:23:51 3: Opening BTag_Mark device 127.0.0.1:5222
2020.05.13 16:23:51 3: BTag_Mark device opened
2020.05.13 16:23:51 3: Opening BTag_Luna device 127.0.0.1:5222
2020.05.13 16:23:51 3: BTag_Luna device opened
2020.05.13 16:23:51 3: Opening BTag_Leon device 127.0.0.1:5222
2020.05.13 16:23:51 3: BTag_Leon device opened
2020.05.13 16:23:51 3: Opening BTag_Nadine device 127.0.0.1:5222
2020.05.13 16:23:51 3: BTag_Nadine device opened
2020.05.13 16:23:52 1: PERL WARNING: Smartmatch is experimental at ./FHEM/47_OBIS.pm line 472.
2020.05.13 16:23:52 1: PERL WARNING: main::OBIS_decodeTL() called too early to check prototype at ./FHEM/47_OBIS.pm line 785.
2020.05.13 16:23:52 3: Opening Zaehler_ED300L device 10.0.0.90:8311
2020.05.13 16:23:52 3: Init done
2020.05.13 16:23:52 3: Zaehler_ED300L device opened
2020.05.13 16:23:54 3: HourCounter HourCounter Initialize.220 Init Done with Version 1.0.1.2 - 24.12.2014
2020.05.13 16:23:54 0: HourCounter Gaszaehler Define.228 parameters: Gaszaehler HourCounter Waschkeller_Zaehler:Gas_Impuls:.1 Waschkeller_Zaehler:Gas_Impuls:.0
2020.05.13 16:23:54 3: Sub BleTagBattery_Define (BleTagBattery) - defined
2020.05.13 16:23:54 3: Opening Forerunner935 device 127.0.0.1:5222
2020.05.13 16:23:54 3: Forerunner935 device opened
2020.05.13 16:23:58 2: Registering BOTVAC Jarvis for URL /BOTVAC/Jarvis/map...
2020.05.13 16:24:00 2: Registering GEOFANCY geofancy for URL /geo...
2020.05.13 16:24:00 3: WEBhook: port 8088 opened
2020.05.13 16:24:00 3: Star: Defined with URL https://www.clever-tanken.de/tankstelle_details/6628 and interval 600 featurelevel 6
2020.05.13 16:24:00 3: Aral: Defined with URL https://www.clever-tanken.de/tankstelle_details/11773 and interval 600 featurelevel 6
2020.05.13 16:24:00 3: Opening Fenix5XPlus device 127.0.0.1:5222
2020.05.13 16:24:00 3: Fenix5XPlus device opened
2020.05.13 16:24:01 0: HourCounter Wasserzaehler Define.228 parameters: Wasserzaehler HourCounter Waschkeller_Zaehler:Wasser_Impuls:.1 Waschkeller_Zaehler:Wasser_Impuls:.0
2020.05.13 16:24:01 0: HourCounter PC_Leon_Betriebsstunden Define.228 parameters: PC_Leon_Betriebsstunden HourCounter PC_Leon:present PC_Leon:absent
2020.05.13 16:24:01 0: OctoPrint 3D_Drucker [OctoPrint_Define] start device
2020.05.13 16:24:03 3: TelegramBot_Define TelegramBot: called 
2020.05.13 16:24:03 3: Opening Mi3_Leon device 127.0.0.1:5222
2020.05.13 16:24:03 3: Mi3_Leon device opened
2020.05.13 16:24:04 3: Opening Mi3_Luna device 127.0.0.1:5222
2020.05.13 16:24:04 3: Mi3_Luna device opened
2020.05.13 16:24:10 1: HMCCU: [CCU3 : 2991] Initialized version 4.3.025
2020.05.13 16:24:10 1: HMCCU: [CCU3 : 2991] HMCCU: Initializing device
2020.05.13 16:24:11 1: HMCCU: [CCU3 : 2991] HMCCU: Read 54 devices with 291 channels from CCU 10.0.0.10
2020.05.13 16:24:11 1: HMCCU: [CCU3 : 2991] HMCCU: Read 3 interfaces from CCU 10.0.0.10
2020.05.13 16:24:11 1: HMCCU: [CCU3 : 2991] HMCCU: Read 6 programs from CCU 10.0.0.10
2020.05.13 16:24:11 1: HMCCU: [CCU3 : 2991] HMCCU: Read 0 virtual groups from CCU 10.0.0.10
2020.05.13 16:24:11 2: HMCCU: [CCU3 : 2991] Updating CCU system variables every 5 seconds
2020.05.13 16:24:11 1: HMCCURPCPROC: [d_rpc000010BidCos_RF : 2991] Initialized version 1.9.001 for interface BidCos-RF with I/O device CCU3
2020.05.13 16:24:12 0: HMCCU: Start of RPC server after FHEM initialization in 12 seconds
2020.05.13 16:24:12 3: Email: connected to imap.gmail.com
2020.05.13 16:24:12 3: Email: logged in to rasphome1183@gmail.com
2020.05.13 16:24:20 3: set Anforderung Nur Warmwasser : Please define Anforderung first
2020.05.13 16:24:20 3: InitTemperatur return value: -1
2020.05.13 16:24:20 2: MyAlexa: starting alexa-fhem: /usr/bin/alexa-fhem -c ./alexa-fhem.cfg -a xx:xx -s
2020.05.13 16:24:20 3: MyAlexa: starting
2020.05.13 16:24:20 3: MyAlexa: using logfile: ./log/alexa-2020-05-13.log
2020.05.13 16:24:20 1: usb create starting
No handlers could be found for logger "Fhem"
2020.05.13 16:24:21 3: Probing ZWDongle device /dev/serial1
2020.05.13 16:24:21 3: Probing CUL device /dev/ttyACM0
2020.05.13 16:24:21 3: Probing TCM_ESP3 device /dev/ttyACM0
2020.05.13 16:24:21 3: Probing ZWDongle device /dev/ttyACM0
2020.05.13 16:24:21 3: Probing SIGNALDuino device /dev/ttyACM0
2020.05.13 16:24:22 3: Probing MYSENSORS device /dev/ttyACM0
2020.05.13 16:24:22 3: Probing ArduCounter device /dev/ttyACM0
2020.05.13 16:24:22 3: Probing ElsnerWS device /dev/ttyACM0
2020.05.13 16:24:23 3: Probing FRM device /dev/ttyACM0
2020.05.13 16:24:28 3: Probing CUL device /dev/ttyAMA0
2020.05.13 16:24:28 3: Probing TCM_ESP3 device /dev/ttyAMA0
2020.05.13 16:24:28 3: Probing ZWDongle device /dev/ttyAMA0
2020.05.13 16:24:29 3: Probing SIGNALDuino device /dev/ttyAMA0
2020.05.13 16:24:29 3: Probing MYSENSORS device /dev/ttyAMA0
2020.05.13 16:24:29 3: Probing ArduCounter device /dev/ttyAMA0
2020.05.13 16:24:29 3: Probing ElsnerWS device /dev/ttyAMA0
2020.05.13 16:24:30 3: Probing FRM device /dev/ttyAMA0
Traceback (most recent call last):
  File "/opt/fhem/tempsetzen.py", line 17, in <module>
    solltemp = int(fh.get_dev_reading("Solltemp", "state"))
TypeError: int() argument must be a string or a number, not 'dict'
2020.05.13 16:24:35 1: usb create end
2020.05.13 16:24:36 0: Featurelevel: 6
2020.05.13 16:24:36 0: Server started with 437 defined entities (fhem.pl:21916/2020-05-11 perl:5.028001 os:linux user:fhem pid:2991)
2020.05.13 16:24:39 3: Opening MQTT device 127.0.0.1:1883
2020.05.13 16:24:39 3: telnetForBlockingFn_1589379879: port 44767 opened
2020.05.13 16:24:39 1: SONOS0: Kein UPnP-Server gefunden... Starte selber einen und warte 8 Sekunde(n) darauf...
2020.05.13 16:24:39 3: DbRep DbRepATemp14 - Connectiontest to database mysql:database=fhemtempfeucht;host=localhost;port=3306 with user fhemuser
2020.05.13 16:24:39 3: DbLog DbLogLicht - Creating Push-Handle to database mysql:database=fhemlicht;host=localhost;port=3306 with user fhemuser
2020.05.13 16:24:39 3: DbLog DbLogLicht - Push-Handle to db mysql:database=fhemlicht;host=localhost;port=3306 created
2020.05.13 16:24:39 3: DbLog DbLogLicht - UTF8 support enabled
2020.05.13 16:24:39 3: DbLog DbLogRemote - Creating Push-Handle to database mysql:database=fhemremote;host=localhost;port=3306 with user fhemuser
2020.05.13 16:24:39 3: DbLog DbLogRemote - Push-Handle to db mysql:database=fhemremote;host=localhost;port=3306 created
2020.05.13 16:24:39 3: DbLog DbLogRemote - UTF8 support enabled
2020.05.13 16:24:39 3: DbLog DbLogBTag - Creating Push-Handle to database mysql:database=fhembtag;host=localhost;port=3306 with user fhemuser
2020.05.13 16:24:39 3: DbLog DbLogBTag - Push-Handle to db mysql:database=fhembtag;host=localhost;port=3306 created
2020.05.13 16:24:39 3: DbLog DbLogBTag - UTF8 support enabled
2020.05.13 16:24:39 3: DbLog DbLogHomestatus - Creating Push-Handle to database mysql:database=fhemhomestatus;host=localhost;port=3306 with user fhemuser
2020.05.13 16:24:39 3: DbLog DbLogHomestatus - Push-Handle to db mysql:database=fhemhomestatus;host=localhost;port=3306 created
2020.05.13 16:24:39 3: DbLog DbLogHomestatus - UTF8 support enabled
2020.05.13 16:24:39 3: DbLog DbLogStrom - Creating Push-Handle to database mysql:database=fhemstrom;host=localhost;port=3306 with user fhemuser
2020.05.13 16:24:39 3: DbLog DbLogStrom - Push-Handle to db mysql:database=fhemstrom;host=localhost;port=3306 created
2020.05.13 16:24:39 3: DbLog DbLogStrom - UTF8 support enabled
2020.05.13 16:24:39 3: DbLog DbLogGas - Creating Push-Handle to database mysql:database=fhemgas;host=localhost;port=3306 with user fhemuser
2020.05.13 16:24:39 3: DbLog DbLogGas - Push-Handle to db mysql:database=fhemgas;host=localhost;port=3306 created
2020.05.13 16:24:39 3: DbLog DbLogGas - UTF8 support enabled
2020.05.13 16:24:40 3: DbRep DbRepHomestatus - Connectiontest to database mysql:database=fhemhomestatus;host=localhost;port=3306 with user fhemuser
2020.05.13 16:24:40 3: DbRep DbRepBTag - Connectiontest to database mysql:database=fhembtag;host=localhost;port=3306 with user fhemuser
2020.05.13 16:24:40 3: DbLog DbLogSystem - Creating Push-Handle to database mysql:database=fhemsystem;host=localhost;port=3306 with user fhemuser
2020.05.13 16:24:40 3: DbLog DbLogSystem - Push-Handle to db mysql:database=fhemsystem;host=localhost;port=3306 created
2020.05.13 16:24:40 3: DbLog DbLogSystem - UTF8 support enabled
2020.05.13 16:24:40 3: DbLog DbLogWasser - Creating Push-Handle to database mysql:database=fhemwasser;host=localhost;port=3306 with user fhemuser
2020.05.13 16:24:40 3: DbLog DbLogWasser - Push-Handle to db mysql:database=fhemwasser;host=localhost;port=3306 created
2020.05.13 16:24:40 3: DbLog DbLogWasser - UTF8 support enabled
2020.05.13 16:24:40 3: DbRep DbRepSystem - Connectiontest to database mysql:database=fhemsystem;host=localhost;port=3306 with user fhemuser
2020.05.13 16:24:40 0: HourCounter Gaszaehler Run.598 first run done countsOverall:49201
2020.05.13 16:24:40 3: DbRep DbRepWasser - Connectiontest to database mysql:database=fhemwasser;host=localhost;port=3306 with user fhemuser
2020.05.13 16:24:40 3: DbRep DbRepHeizung - Connectiontest to database mysql:database=fhemheizung;host=localhost;port=3306 with user fhemuser
2020.05.13 16:24:40 3: DbRep DbRepGas - Connectiontest to database mysql:database=fhemgas;host=localhost;port=3306 with user fhemuser
2020.05.13 16:24:40 0: HourCounter Wasserzaehler Run.598 first run done countsOverall:600615
2020.05.13 16:24:40 0: HourCounter PC_Leon_Betriebsstunden Run.598 first run done countsOverall:416
2020.05.13 16:24:40 2: HMCCU: [CCU3 : 2991] Get RPC device for interface BidCos-RF
2020.05.13 16:24:40 2: HMCCURPCPROC: [d_rpc000010BidCos_RF : 2991] RPC server process started for interface BidCos-RF with PID=3222
2020.05.13 16:24:40 2: HMCCURPCPROC: [d_rpc000010BidCos_RF : 3222] Initializing RPC server CB2001000008000010 for interface BidCos-RF
2020.05.13 16:24:40 1: HMCCURPCPROC: [d_rpc000010BidCos_RF : 2991] RPC server starting
2020.05.13 16:24:41 3: DbRep DbRepRaumTemp - Connectiontest to database mysql:database=fhemtempfeucht;host=localhost;port=3306 with user fhemuser
2020.05.13 16:24:41 3: DbRep DbRepRemote - Connectiontest to database mysql:database=fhemremote;host=localhost;port=3306 with user fhemuser
2020.05.13 16:24:41 2: HMCCURPCPROC: [d_rpc000010BidCos_RF : 3222] Callback server CB2001000008000010 created. Listening on port 7411
2020.05.13 16:24:41 2: HMCCURPCPROC: [d_rpc000010BidCos_RF : 3222] CB2001000008000010 accepting connections. PID=3222
2020.05.13 16:24:41 3: DbRep DbRepATemp - Connectiontest to database mysql:database=fhemtempfeucht;host=localhost;port=3306 with user fhemuser
2020.05.13 16:24:41 3: DbRep DbRepLicht - Connectiontest to database mysql:database=fhemlicht;host=localhost;port=3306 with user fhemuser
2020.05.13 16:24:41 3: DbRep DbRepStrom - Connectiontest to database mysql:database=fhemstrom;host=localhost;port=3306 with user fhemuser
2020.05.13 16:24:41 3: MQTT device opened
2020.05.13 16:24:41 1: SONOS0: ./FHEM/00_SONOS.pm is started by fhem...
2020.05.13 16:24:41 1: SONOS0: ./FHEM/00_SONOS.pm is listening to Port 4711
2020.05.13 16:24:41 1: FHEMWEB SSL/HTTPS error:  SSL accept attempt failed (peer: 127.0.0.1)
2020.05.13 16:24:42 2: HMCCURPCPROC: [d_rpc000010BidCos_RF : 2991] RPC server CB2001000008000010 enters server loop
2020.05.13 16:24:42 2: HMCCURPCPROC: [d_rpc000010BidCos_RF : 2991] Registering callback http://10.0.0.8:7411/fh2001 of type A with ID CB2001000008000010 at http://Admin:wuzdaV-bugqof-7komju@10.0.0.10:2001
2020.05.13 16:24:42 1: HMCCURPCPROC: [d_rpc000010BidCos_RF : 2991] RPC server CB2001000008000010 running
2020.05.13 16:24:42 1: HMCCU: [CCU3 : 2991] All RPC servers running
2020.05.13 16:24:42 2: HMCCU: [CCU3 : 2991] Updating 45 of 45 client devices matching devexp=.* filter=ccudevstate=active,ccuif=BidCos-RF
2020.05.13 16:24:42 1: HMCCURPCPROC: [d_rpc000010BidCos_RF : 2991] Scheduled CCU ping every 300 seconds
2020.05.13 16:24:42 3: DbRep DbRepTemperaturFeuchte - Connectiontest to database mysql:database=fhemtempfeucht;host=localhost;port=3306 with user fhemuser
2020.05.13 16:24:42 3: DbRep DbRepATemp14 - Index Report_Idx exists. Check ok
2020.05.13 16:24:42 3: DbRep DbRepATemp14 - Initial data information retrieved successfully - total time used: 0.0094 seconds
2020.05.13 16:24:43 3: DbRep DbRepATemp14 - Connectiontest to db mysql:database=fhemtempfeucht;host=localhost;port=3306 successful
2020.05.13 16:24:43 3: DbRep DbRepHomestatus - Index Report_Idx exists. Check ok
2020.05.13 16:24:43 3: DbRep DbRepHomestatus - Initial data information retrieved successfully - total time used: 0.0090 seconds
2020.05.13 16:24:43 2: HMCCURPCPROC: [d_rpc000010BidCos_RF : 3222] CB2001000008000010 NewDevice received 293 device and channel specifications
2020.05.13 16:24:43 3: DbRep DbRepHomestatus - Connectiontest to db mysql:database=fhemhomestatus;host=localhost;port=3306 successful
2020.05.13 16:24:43 3: DbRep DbRepBTag - Index Report_Idx exists. Check ok
2020.05.13 16:24:43 3: DbRep DbRepBTag - Initial data information retrieved successfully - total time used: 0.0087 seconds
2020.05.13 16:24:43 2: AttrTemplates: got 158 entries
2020.05.13 16:24:46 2: HMCCU: [CCU3 : 2991] Update success=45 failed=0
2020.05.13 16:24:46 3: Aral: Read callback: Error: read from https://www.clever-tanken.de:443 timed out
2020.05.13 16:24:46 3: Star: Read callback: Error: read from https://www.clever-tanken.de:443 timed out
2020.05.13 16:24:46 3: DbRep DbRepSystem - Index Report_Idx exists. Check ok
2020.05.13 16:24:46 3: DbRep DbRepSystem - Initial data information retrieved successfully - total time used: 0.0095 seconds
2020.05.13 16:24:48 3: DbRep DbRepBTag - Connectiontest to db mysql:database=fhembtag;host=localhost;port=3306 successful
2020.05.13 16:24:48 3: DbRep DbRepSystem - Connectiontest to db mysql:database=fhemsystem;host=localhost;port=3306 successful
2020.05.13 16:24:48 3: DbRep DbRepWasser - Index Report_Idx exists. Check ok
2020.05.13 16:24:48 3: DbRep DbRepWasser - Initial data information retrieved successfully - total time used: 0.0101 seconds
2020.05.13 16:24:48 3: Spülmaschine: Programmstart
2020.05.13 16:24:48 1: Calendar Muelltonnen_Kalender: retrieval failed with HTTP response code 403
2020.05.13 16:24:48 1: Calendar Muelltonnen_Kalender: retrieved no or empty data
2020.05.13 16:24:48 3: ABFALL Muelltonnen - CALENDAR:Muelltonnen_Kalender triggered, updating ABFALL Muelltonnen ...
2020.05.13 16:24:49 3: DbRep DbRepHeizung - Index Report_Idx exists. Check ok
2020.05.13 16:24:49 3: DbRep DbRepHeizung - Initial data information retrieved successfully - total time used: 0.0120 seconds
2020.05.13 16:24:49 3: DbRep DbRepWasser - Connectiontest to db mysql:database=fhemwasser;host=localhost;port=3306 successful
2020.05.13 16:24:49 1: SONOS1: UPnP-Thread gestartet.
2020.05.13 16:24:49 1: SONOS2: LongJobs-Thread gestartet. Prüfe auf LongJobs...
2020.05.13 16:24:50 1: SONOS3: IsAlive-Thread gestartet. Warte 120 Sekunden und pruefe dann alle 45 Sekunden...
2020.05.13 16:24:50 1: SONOS4: Restore-Thread gestartet. Warte auf Arbeit...
2020.05.13 16:24:50 3: DbRep DbRepHeizung - Connectiontest to db mysql:database=fhemheizung;host=localhost;port=3306 successful
2020.05.13 16:24:51 3: DbRep DbRepGas - Index Report_Idx exists. Check ok
2020.05.13 16:24:51 3: DbRep DbRepGas - Initial data information retrieved successfully - total time used: 0.0098 seconds
2020.05.13 16:24:52 3: DbRep DbRepGas - Connectiontest to db mysql:database=fhemgas;host=localhost;port=3306 successful
2020.05.13 16:24:53 3: DbRep DbRepRaumTemp - Index Report_Idx exists. Check ok
2020.05.13 16:24:53 3: DbRep DbRepRaumTemp - Initial data information retrieved successfully - total time used: 0.0155 seconds
2020.05.13 16:24:53 3: DbRep DbRepRemote - Index Report_Idx exists. Check ok
2020.05.13 16:24:53 3: DbRep DbRepATemp - Index Report_Idx exists. Check ok
2020.05.13 16:24:53 3: DbRep DbRepLicht - Index Report_Idx exists. Check ok
2020.05.13 16:24:53 3: DbRep DbRepATemp - Initial data information retrieved successfully - total time used: 0.0218 seconds
2020.05.13 16:24:53 3: DbRep DbRepLicht - Initial data information retrieved successfully - total time used: 0.0186 seconds
2020.05.13 16:24:53 3: DbRep DbRepRemote - Initial data information retrieved successfully - total time used: 0.0382 seconds
2020.05.13 16:24:53 3: DbRep DbRepStrom - Index Report_Idx exists. Check ok
2020.05.13 16:24:53 3: DbRep DbRepStrom - Initial data information retrieved successfully - total time used: 0.0104 seconds
2020.05.13 16:24:53 3: DbRep DbRepRaumTemp - Connectiontest to db mysql:database=fhemtempfeucht;host=localhost;port=3306 successful
2020.05.13 16:24:54 3: DbRep DbRepStrom - Connectiontest to db mysql:database=fhemstrom;host=localhost;port=3306 successful
2020.05.13 16:24:54 3: DbRep DbRepTemperaturFeuchte - Index Report_Idx exists. Check ok
2020.05.13 16:24:54 3: DbRep DbRepRemote - Connectiontest to db mysql:database=fhemremote;host=localhost;port=3306 successful
2020.05.13 16:24:54 3: DbRep DbRepTemperaturFeuchte - Initial data information retrieved successfully - total time used: 0.0102 seconds
2020.05.13 16:24:54 3: DbRep DbRepLicht - Connectiontest to db mysql:database=fhemlicht;host=localhost;port=3306 successful
2020.05.13 16:24:54 3: DbRep DbRepATemp - Connectiontest to db mysql:database=fhemtempfeucht;host=localhost;port=3306 successful
2020.05.13 16:24:54 3: DbRep DbRepTemperaturFeuchte - Connectiontest to db mysql:database=fhemtempfeucht;host=localhost;port=3306 successful
2020.05.13 16:25:33 3: TelegramBot_Callback TelegramBot: Digest: Number of poll failures on 2020-05-12 is :3:
2020.05.13 16:26:56 1: SONOS1: Service-subscribing not possible due to missing TransportService
Subscription request failed with error: 503 Service Unavailable at ./FHEM/00_SONOS.pm line 6098 thread 1.
2020.05.13 16:26:56 1: SONOS1: Rendering-Service-subscribing NOT successful: 
2020.05.13 16:26:57 1: SONOS1: Service-subscribing not possible due to missing TransportService
Subscription request failed with error: 503 Service Unavailable at ./FHEM/00_SONOS.pm line 6098 thread 1.
2020.05.13 16:26:57 1: SONOS1: Rendering-Service-subscribing NOT successful: 
2020.05.13 16:26:58 1: SONOS1: Service-subscribing not possible due to missing TransportService
Subscription request failed with error: 503 Service Unavailable at ./FHEM/00_SONOS.pm line 6098 thread 1.
2020.05.13 16:26:58 1: SONOS1: Rendering-Service-subscribing NOT successful: 
2020.05.13 16:26:59 1: SONOS1: Service-subscribing not possible due to missing TransportService
Subscription request failed with error: 503 Service Unavailable at ./FHEM/00_SONOS.pm line 6098 thread 1.
2020.05.13 16:26:59 1: SONOS1: Rendering-Service-subscribing NOT successful:

Otto123 · 13 Mai 2020, 16:33:15

Laut deinem LogFile von FHEM startet er genau einmal.

Sagt eigentlich auch der status von systemctl.

Irgendwas macht immer wieder Prozesse zur configDb auf? Da stimmt irgendwas mit Deiner DB nicht? Da muss jemand anders helfen

Im Start in der Kommandozeile mit perl ... bist Du der falsche user, da darf er verschiedenen Sachen nicht. Das brauchst Du aber auch nicht machen. start mit

Code Auswählen

sudo systemctl start fhemist ok.

Beta-User · 13 Mai 2020, 16:37:17

Hmm, mehrere parallele Perl-Prozesse gibt es bei mir auch, wenn auch nicht so viele. Hängt aber vermutlich davon ab, ob es viele zu forkende Defs gibt (alles, was potentiell blocking ist...), und wie schnell da Antworten kommen (z.B. bei externen HTTPMODs). Hier klingt das nach Sonos? (Und auch DBLog forkt, afaik). (@Otto123: Wie kommst du auf configDB? Wenn da was nicht paßt, dürfte "nüscht" passieren, weil dann einfach keine config da ist, die geladen werden kann. Das ist ein einmaliger Vorgang...).

Würde mal vorschlagen, den systemd-Dienst in Ruhe zu lassen, das Demo-System hochzufahren und erst mal ein update drüber zu bügeln, falls noch nicht geschehen?
Ansonsten configDB mal im Rettungsmodus starten?

Da scheinen auch weitere externe Dinge zu laufen bzw. erforderlich zu sein. Paßt das alles schon zusammen?

Otto123 · 13 Mai 2020, 16:39:34

~~Du meinst > 20 configDb Prozesse ist normal? Jede def macht einen Prozess? grusel ....~~
Edit: War ein Fehler in der Interpretation

Sucht valvak nach einem Geist und alles ist in Ordnung? Ich sehe sonst nichts schlimmes

valvak · 13 Mai 2020, 16:42:32

Also update lief schon.

Ich habe die einzelnen Module und Pakete nach und nach installiert bis die configDB zufrieden war. in Fhem selber wird ja auch kein Fehler angezeigt. Alles funktioniert wie es soll, nur eben EXTREM langsam.

Ich habe die Datenbanken per SQL-Dump aus dem alten System gezogen und per Import in die neuen Datenbanken. Es ist wie gesagt 1:1 die selbe Konfig. Wenn ich die alte SD-Karte in den Raspberry packe klappt es.

Und wie gesagt wenn ich ne leere ConfigDB starten bleibt der Load auch unten.

Beta-User · 13 Mai 2020, 16:48:16

Zitat von: Otto123 am 13 Mai 2020, 16:39:34
Du meinst > 20 configDb Prozesse ist normal? Jede def macht einen Prozess? grusel ....

Sucht valvak nach einem Geist und alles ist in Ordnung? Ich sehe sonst nichts schlimmes

Ich sehe in

Zitat von: valvak am 13 Mai 2020, 16:30:33
[...]

auch viele Datenbank-Prozesse, aber keinen, der zu configDB gehört... Das ist alles DBLog bzw. das dazu gehörende DBRep. Beides hat mit configDB nichts zu tun (ich starte mit einer sqlite-DB unter configDB, das logging erfolgt dann in MariaDB (früher FileLog)... Ist was komplett getrenntes)!

Kann es sein, dass die Zugangsdaten zur Datenbank (LogDB!) woanders gespeichert sind (die ID-file für getKeyValue) und die fehlt?