Hallo Zusammen,
bei mir verabschiedet sich sporadisch ein/der FHEM Dienst und ich habe keinen blassen Schimmer warum....
FHEM Log:
2015.12.23 08:36:13 3: get Cube credit10ms : Cube credit10ms => 1800
2015.12.23 08:41:13 3: get Cube credit10ms : Cube credit10ms => 1766
2015.12.23 08:46:13 3: get Cube credit10ms : Cube credit10ms => 1800
2015.12.23 08:51:13 3: get Cube credit10ms : Cube credit10ms => 1800
2015.12.23 08:56:13 3: get Cube credit10ms : Cube credit10ms => 1556
2015.12.23 09:01:13 3: get Cube credit10ms : Cube credit10ms => 1622
2015.12.23 09:06:13 3: get Cube credit10ms : Cube credit10ms => 1376
2015.12.23 09:11:13 3: get Cube credit10ms : Cube credit10ms => 1658
2015.12.23 09:16:13 3: get Cube credit10ms : Cube credit10ms => 1800
2015.12.23 09:21:16 3: get Cube credit10ms : Cube credit10ms => 1498
2015.12.23 09:26:13 3: get Cube credit10ms : Cube credit10ms => 1796
2015.12.23 09:31:13 3: get Cube credit10ms : Cube credit10ms => 1800
2015.12.23 09:36:13 3: get Cube credit10ms : Cube credit10ms => 1616
2015.12.23 09:41:13 3: get Cube credit10ms : Cube credit10ms => 1800
2015.12.23 09:46:13 3: get Cube credit10ms : Cube credit10ms => 1436
2015.12.23 09:51:13 3: get Cube credit10ms : Cube credit10ms => 1736
2015.12.23 09:56:13 3: get Cube credit10ms : Cube credit10ms => 1800
2015.12.23 10:01:13 3: get Cube credit10ms : Cube credit10ms => 1520
2015.12.23 10:06:13 3: get Cube credit10ms : Cube credit10ms => 1800
2015.12.23 10:11:13 3: get Cube credit10ms : Cube credit10ms => 1376
2015.12.23 10:16:13 3: get Cube credit10ms : Cube credit10ms => 1667
2015.12.23 10:21:13 3: get Cube credit10ms : Cube credit10ms => 1800
2015.12.23 10:26:13 3: get Cube credit10ms : Cube credit10ms => 1496
2015.12.23 10:31:13 3: get Cube credit10ms : Cube credit10ms => 1558
2015.12.23 10:36:13 3: get Cube credit10ms : Cube credit10ms => 1800
2015.12.23 10:41:13 3: get Cube credit10ms : Cube credit10ms => 1616
2015.12.23 10:46:13 3: get Cube credit10ms : Cube credit10ms => 1800
2015.12.23 10:51:13 3: get Cube credit10ms : Cube credit10ms => 1427
2015.12.23 10:56:13 3: get Cube credit10ms : Cube credit10ms => 1727
2015.12.23 11:01:13 3: get Cube credit10ms : Cube credit10ms => 1800
2015.12.23 11:06:16 3: get Cube credit10ms : Cube credit10ms => 1549
2015.12.23 11:11:13 3: get Cube credit10ms : Cube credit10ms => 1800
2015.12.23 11:16:13 3: get Cube credit10ms : Cube credit10ms => 1376
2015.12.23 11:21:13 3: get Cube credit10ms : Cube credit10ms => 1667
2015.12.23 11:26:13 3: get Cube credit10ms : Cube credit10ms => 1800
2015.12.23 11:31:13 3: get Cube credit10ms : Cube credit10ms => 1496
2015.12.23 11:36:13 3: get Cube credit10ms : Cube credit10ms => 1796
2015.12.23 11:41:13 3: get Cube credit10ms : Cube credit10ms => 1800
2015.12.23 11:46:13 3: get Cube credit10ms : Cube credit10ms => 1616
2015.12.23 11:51:13 3: get Cube credit10ms : Cube credit10ms => 1800
2015.12.23 11:56:13 3: get Cube credit10ms : Cube credit10ms => 1436
2015.12.23 12:01:13 3: get Cube credit10ms : Cube credit10ms => 1736
2015.12.23 12:06:13 3: get Cube credit10ms : Cube credit10ms => 1800
2015.12.23 12:11:13 3: get Cube credit10ms : Cube credit10ms => 1775
2015.12.23 12:16:13 3: get Cube credit10ms : Cube credit10ms => 1800
2015.12.23 12:21:13 3: get Cube credit10ms : Cube credit10ms => 1376
2015.12.23 12:26:13 3: get Cube credit10ms : Cube credit10ms => 1676
2015.12.23 12:31:13 3: get Cube credit10ms : Cube credit10ms => 1800
2015.12.23 12:36:13 3: get Cube credit10ms : Cube credit10ms => 1496
2015.12.23 12:41:13 3: get Cube credit10ms : Cube credit10ms => 1796
2015.12.23 12:46:13 3: get Cube credit10ms : Cube credit10ms => 1800
2015.12.23 12:51:16 3: get Cube credit10ms : Cube credit10ms => 1618
2015.12.23 12:56:13 3: get Cube credit10ms : Cube credit10ms => 1800
2015.12.23 13:01:13 3: get Cube credit10ms : Cube credit10ms => 1436
2015.12.23 15:21:12 2: MAX MaxScan: UtilsMaxScan_Initialize.86 MaxScan is starting
2015.12.23 15:21:12 1: Including fhem.cfg
2015.12.23 15:21:13 3: telnetPort: port 7072 opened
2015.12.23 15:21:13 3: WEB: port 8083 opened
2015.12.23 15:21:13 3: WEBphone: port 8084 opened
2015.12.23 15:21:13 3: WEBtablet: port 8085 opened
2015.12.23 15:21:14 2: eventTypes: loaded 846 events from ./log/eventTypes.txt
2015.12.23 15:21:14 3: Opening FritzCM device 192.168.100.10:1012
2015.12.23 15:21:14 3: FritzCM device opened
2015.12.23 15:21:15 3: Opening Cube device 192.168.100.25:2323
2015.12.23 15:21:15 3: Cube device opened
2015.12.23 15:21:16 3: Cube: Possible commands: BbCFiAZNEkGMKLUYRTVWXefltxz
2015.12.23 15:21:16 2: Switched Cube rfmode to MAX
2015.12.23 15:21:16 3: CUL_MAX_Check: Detected firmware version 154 of the CUL-compatible IODev
2015.12.23 15:21:16 3: TABLETUI: new ext defined infix:ftui/: dir:./www/tablet:
2015.12.23 15:21:16 3: Registering HTTPSRV TABLETUI for URL /ftui and assigned link ftui/ ...
2015.12.23 15:21:36 1: Including ./log/fhem.save
2015.12.23 15:21:36 0: Featurelevel: 5.7
2015.12.23 15:21:36 0: Server started with 117 defined entities (fhem.pl:10116/2015-12-06 perl:5.020002 os:linux user:fhem pid:409)
2015.12.23 15:21:36 3: telnetForBlockingFn: port 46495 opened
Sagt also quasi nichts aus....scheint einfach weg zu sein.
Ein "ps -ax | grep fhem" bringt normaler Weise folgendes Ergebnis:
409 ? S 0:05 perl fhem.pl fhem.cfg
884 pts/0 S+ 0:00 grep fhem
Im Fehlerfall fehlt die erste Zeile komplett...FHEM scheint also wirklich beendet zu sein...nur warum?
Bräuchte bitte mal Tips wie und wo ich ein genaueres Logging für FHEM selbst aktivieren kann...
Danke und ein schönes Weihnachtsfest,
Kharim
Du hattest den dienst wieder gestartet?
...
2015.12.23 13:01:13 3: get Cube credit10ms : Cube credit10ms => 1436
2015.12.23 15:21:12 2: MAX MaxScan: UtilsMaxScan_Initialize.86 MaxScan is starting
...
Was sagt denn zu der Uhrzeit das "/var/log/kern.log"?
Ansonsten kannst Du nur probieren, den Loglevel hochzudrehen, d.h. verbose auf 5 setzen
Zitat von: Wernieman am 23 Dezember 2015, 15:41:09
Du hattest den dienst wieder gestartet?
Was sagt denn zu der Uhrzeit das "/var/log/kern.log"?
Ansonsten kannst Du nur probieren, den Loglevel hochzudrehen, d.h. verbose auf 5 setzen
Jap..."irgendwann" merkt man ja mal, dass die FHEM Seite nicht erreichbar ist und da hab ich den Pi neu gestartet.
kern.log sagt auch nicht mehr....erstaunlicher Weise sogar noch viel weniger.....
Dec 22 20:56:07 minibian kernel: [ 7.550814] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
Dec 22 20:56:07 minibian kernel: [ 7.559779] smsc95xx 1-1.1:1.0 eth0: link up, 100Mbps, full-duplex, lpa 0x4DE1
Dec 22 20:56:07 minibian kernel: [ 9.483193] random: nonblocking pool is initialized
Dec 23 15:21:11 minibian kernel: [ 0.000000] Booting Linux on physical CPU 0xf00
Dec 23 15:21:11 minibian kernel: [ 0.000000] Initializing cgroup subsys cpuset
Dec 23 15:21:11 minibian kernel: [ 0.000000] Initializing cgroup subsys cpu
Dec 23 15:21:11 minibian kernel: [ 0.000000] Initializing cgroup subsys cpuacct
Blöde Frage ich weiß....aber wo muss ich das verbose 5 einstellen?
Kenne das bisher nur an einzelnen Geräten (zb. CUL) oder eben an Notifys....aber am FHEM selbst?
Danke,
Kharim
global verbose auf 5 setzen ;)
VG
Frank
Siehe auch die Doku:
http://fhem.de/commandref.html (http://fhem.de/commandref.html)
ZitatGlobal attributes used by all devices
verbose
Set the verbosity level. Possible values:
0 - server start/stop
1 - error messages or unknown packets
2 - major events/alarms.
3 - commands sent out will be logged.
4 - you'll see whats received by the different devices.
5 - debugging.
The value for the global device is a default for other devices without own verbose attribute set.
Alles klar, ich danke.
Ist nun eingestellt....mal schauen was die nächsten Tage bringen.
Schöne Weihnacht,
Kharim
Soo hier nun mal ein Stück Log zum Zeitpunkt eines Restarts:
2015.12.24 12:50:00 5: SYSMON RaspiDaten: Exec_Local.4090 Execute '[ -f /sys/class/net/eth0/statistics/rx_bytes ] && echo 1 || echo 0'
2015.12.24 12:50:00 5: SYSMON RaspiDaten: Exec_Local.4103 Result '1'
2015.12.24 12:50:00 5: SYSMON RaspiDaten: Exec_Local.4090 Execute 'cat /sys/class/net/eth0/statistics/rx_bytes'
2015.12.24 12:50:00 5: SYSMON RaspiDaten: Exec_Local.4103 Result '2310924'
2015.12.24 12:50:00 5: SYSMON RaspiDaten: Exec_Local.4090 Execute 'cat /sys/class/net/eth0/statistics/tx_bytes'
2015.12.24 12:50:00 5: SYSMON RaspiDaten: Exec_Local.4103 Result '8244045'
2015.12.24 12:50:00 5: SYSMON RaspiDaten: Exec_Local.4090 Execute '[ -f /sys/class/net/eth0/speed ] && cat /sys/class/net/eth0/speed 2>/dev/null || echo not available'
2015.12.24 12:50:00 5: SYSMON RaspiDaten: Exec_Local.4103 Result '100'
2015.12.24 12:50:00 5: SYSMON RaspiDaten: getNetworkInfo.2650 get wlan0
2015.12.24 12:50:00 5: SYSMON RaspiDaten: Exec_Local.4090 Execute 'ifconfig wlan0 2>&1'
2015.12.24 12:50:00 5: SYSMON RaspiDaten: Exec_Local.4103 Result 'wlan0: Fehler beim Auslesen der Schnittstelleninformation: Ger�t nicht gefunden'
2015.12.24 12:50:00 5: SYSMON RaspiDaten: getNetworkInfo.2662 SYSMON_getNetworkInfo>>>>>>>>>>>>>>>>$VAR1 = 'wlan0: Fehler beim Auslesen der Schnittstelleninformation: Ger�t nicht gefunden';
2015.12.24 12:50:00 4: Connection accepted from telnet:127.0.0.1:53631
2015.12.24 12:50:00 5: Cmd: >{SYSMON_blockingFinish('name|RaspiDaten|cpu0_idle_stat|31.04 99.86 95.99|uptime_text|0 days, 04 hours, 49 minutes|stat_cpu0_percent|3.33 0.00 6.36 90.21 0.02 0.00 0.08|cpu_core_count|4|eth0_tx|8244045|stat_cpu2_diff|390 0 346 5618 0 0 7|stat_cpu0_diff|203 0 387 5491 1 0 5|stat_cpu_diff|930 0 1442 22541 1 0 39|stat_cpu_text|user: 3.73 %, nice: 0.00 %, sys: 5.78 %, idle: 90.33 %, io: 0.00 %, irq: 0.00 %, sirq: 0.16 %|uptime|17369|stat_cpu3_diff|181 0 391 5692 0 0 16|cpu3_idle_stat|32.93 99.94 96.39|cpu_temp_avg|48.3|stat_cpu1_diff|156 0 318 5740 0 0 11|cpu_temp_stat|40.08 57.30 48.23|ram_used_stat|101.02 171.26 155.61|fhemstarttime_text|24.12.2015 08:00:51|stat_cpu2|29554 0 22262 1671830 502 0 301|cpu2_idle_stat|28.27 99.90 95.08|loadavg|0.24 0.12 0.12|starttime|1450940430|idletime|16815 96.81 %|eth0|RX: 2.20 MB, TX: 7.86 MB, Total: 10.06 MB|stat_cpu3|30539 0 23491 1669993 365 0 361|fhemstarttime|1450940451|eth0_diff|RX: 0.01 MB, TX: 0.00 MB, Total: 0.01 MB|ram|Total: 973.46 MB, Used: 156.45 MB, 16.07 %, Free: 817.01 MB|eth0_ip|192.168.100.30|wlan0_diff|not available|eth0_speed|100|stat_cpu1|33894 0 22555 1671743 345 0 346|starttime_text|24.12.2015 08:00:30|stat_cpu2_percent|6.13 0.00 5.44 88.32 0.00 0.00 0.11|stat_cpu2_text|user: 6.13 %, nice: 0.00 %, sys: 5.44 %, idle: 88.32 %, io: 0.00 %, irq: 0.00 %, sirq: 0.11 %|stat_cpu_percent|3.73 0.00 5.78 90.33 0.00 0.00 0.16|stat_cpu1_text|user: 2.51 %, nice: 0.00 %, sys: 5.11 %, idle: 92.21 %, io: 0.00 %, irq: 0.00 %, sirq: 0.18 %|stat_cpu0_text|user: 3.33 %, nice: 0.00 %, sys: 6.36 %, idle: 90.21 %, io: 0.02 %, irq: 0.00 %, sirq: 0.08 %|fhemuptime|17349|fhemuptime_text|0 days, 04 hours, 49 minutes|cpu_idle_stat|55.74 99.18 95.85|cpu_temp|50.84|eth0_ip6|fe80::ba27:ebff:fef9:a119/64|idletime_text|0 days, 04 hours, 40 minutes (96.81 %)|stat_cpu1_percent|2.51 0.00 5.11 92.21 0.00 0.00 0.18|eth0_rx|2310924|stat_cpu|126071 0 90121 6676648 1883 1 1534|swap_used_stat|0.00 0.00 0.00|stat_cpu0|32084 0 21813 1663082 671 1 526|swap|n/a|cpu1_idle_stat|27.08 99.97 95.98|wlan0|not available|stat_cpu3_text|user: 2.88 %, nice: 0.00 %, sys: 6.23 %, idle: 90.64 %, io: 0.00 %, irq: 0.00 %, sirq: 0.25 %|stat_cpu3_percent|2.88 0.00 6.23 90.64 0.00 0.00 0.25')}<
2015.12.24 12:50:00 5: SYSMON RaspiDaten: blockingFinish.1034 name|RaspiDaten|cpu0_idle_stat|31.04 99.86 95.99|uptime_text|0 days, 04 hours, 49 minutes|stat_cpu0_percent|3.33 0.00 6.36 90.21 0.02 0.00 0.08|cpu_core_count|4|eth0_tx|8244045|stat_cpu2_diff|390 0 346 5618 0 0 7|stat_cpu0_diff|203 0 387 5491 1 0 5|stat_cpu_diff|930 0 1442 22541 1 0 39|stat_cpu_text|user: 3.73 %, nice: 0.00 %, sys: 5.78 %, idle: 90.33 %, io: 0.00 %, irq: 0.00 %, sirq: 0.16 %|uptime|17369|stat_cpu3_diff|181 0 391 5692 0 0 16|cpu3_idle_stat|32.93 99.94 96.39|cpu_temp_avg|48.3|stat_cpu1_diff|156 0 318 5740 0 0 11|cpu_temp_stat|40.08 57.30 48.23|ram_used_stat|101.02 171.26 155.61|fhemstarttime_text|24.12.2015 08:00:51|stat_cpu2|29554 0 22262 1671830 502 0 301|cpu2_idle_stat|28.27 99.90 95.08|loadavg|0.24 0.12 0.12|starttime|1450940430|idletime|16815 96.81 %|eth0|RX: 2.20 MB, TX: 7.86 MB, Total: 10.06 MB|stat_cpu3|30539 0 23491 1669993 365 0 361|fhemstarttime|1450940451|eth0_diff|RX: 0.01 MB, TX: 0.00 MB, Total: 0.01 MB|ram|Total: 973.46 MB, Used: 156.45 MB, 16.07 %, Free: 817.01 MB|eth0_ip|192.168.100.30|wlan0_diff|not available|eth0_speed|100|stat_cpu1|33894 0 22555 1671743 345 0 346|starttime_text|24.12.2015 08:00:30|stat_cpu2_percent|6.13 0.00 5.44 88.32 0.00 0.00 0.11|stat_cpu2_text|user: 6.13 %, nice: 0.00 %, sys: 5.44 %, idle: 88.32 %, io: 0.00 %, irq: 0.00 %, sirq: 0.11 %|stat_cpu_percent|3.73 0.00 5.78 90.33 0.00 0.00 0.16|stat_cpu1_text|user: 2.51 %, nice: 0.00 %, sys: 5.11 %, idle: 92.21 %, io: 0.00 %, irq: 0.00 %, sirq: 0.18 %|stat_cpu0_text|user: 3.33 %, nice: 0.00 %, sys: 6.36 %, idle: 90.21 %, io: 0.02 %, irq: 0.00 %, sirq: 0.08 %|fhemuptime|17349|fhemuptime_text|0 days, 04 hours, 49 minutes|cpu_idle_stat|55.74 99.18 95.85|cpu_temp|50.84|eth0_ip6|fe80::ba27:ebff:fef9:a119/64|idletime_text|0 days, 04 hours, 40 minutes (96.81 %)|stat_cpu1_percent|2.51 0.00 5.11 92.21 0.00 0.00 0.18|eth0_rx|2310924|stat_cpu|126071 0 90121 6676648 1883 1 1534|swap_used_stat|0.00 0.00 0.00|stat_cpu0|32084 0 21813 1663082 671 1 526|swap|n/a|cpu1_idle_stat|27.08 99.97 95.98|wlan0|not available|stat_cpu3_text|user: 2.88 %, nice: 0.00 %, sys: 6.23 %, idle: 90.64 %, io: 0.00 %, irq: 0.00 %, sirq: 0.25 %|stat_cpu3_percent|2.88 0.00 6.23 90.64 0.00 0.00 0.25
2015.12.24 12:50:00 5: SYSMON RaspiDaten: updateReadings.1053
2015.12.24 12:50:00 5: Triggering RaspiDaten (6 changes)
2015.12.24 12:50:00 5: Notify loop for RaspiDaten loadavg: 0.24 0.12 0.12
ERROR: dutycycle not 0-range (default 255)
-8
ERROR: dutycycle not 0-range (default 255)
-8
ERROR: dutycycle not 0-range (default 255)
-8
2015.12.24 12:50:09 5: redefine at command cpuscript as +*00:00:10 {my $value = qx(/Lars/Scripte/cpulast.sh &);fhem("set cpu $value")}
2015.12.24 12:50:09 5: redefine at command cputempscript as +*00:00:30 {my $value = qx(/Lars/Scripte/cputemp.sh &);fhem("set cputemp $value")}
ERROR: dutycycle not 0-range (default 255)
-8
ERROR: dutycycle not 0-range (default 255)
-8
ERROR: dutycycle not 0-range (default 255)
-8
2015.12.24 12:50:19 5: redefine at command cpuscript as +*00:00:10 {my $value = qx(/Lars/Scripte/cpulast.sh &);fhem("set cpu $value")}
ERROR: dutycycle not 0-range (default 255)
-8
ERROR: dutycycle not 0-range (default 255)
-8
ERROR: dutycycle not 0-range (default 255)
-8
2015.12.24 12:50:29 5: redefine at command cpuscript as +*00:00:10 {my $value = qx(/Lars/Scripte/cpulast.sh &);fhem("set cpu $value")}
ERROR: dutycycle not 0-range (default 255)
-8
ERROR: dutycycle not 0-range (default 255)
-8
ERROR: dutycycle not 0-range (default 255)
-8
ERROR: dutycycle not 0-range (default 255)
-8
2015.12.24 12:50:39 5: redefine at command cpuscript as +*00:00:10 {my $value = qx(/Lars/Scripte/cpulast.sh &);fhem("set cpu $value")}
2015.12.24 12:50:39 5: redefine at command cputempscript as +*00:00:30 {my $value = qx(/Lars/Scripte/cputemp.sh &);fhem("set cputemp $value")}
2015.12.24 12:50:39 5: redefine at command ramscript as +*00:01:00 {my $value = qx(/Lars/Scripte/memfree.sh &);fhem("set ram $value")}
2015.12.24 12:50:41 5: exec at command CreditsScript
2015.12.24 12:50:41 5: Cmd: >{my $value=fhem("get Cube credit10ms");;fhem("set aktCredits $value")}<
2015.12.24 12:50:41 5: Cmd: >get Cube credit10ms<
2015.12.24 12:50:41 5: Triggering Cube (1 changes)
2015.12.24 12:50:41 5: Notify loop for Cube UNKNOWNCODE 21 1536
2015.12.24 12:50:42 1: PERL WARNING: Use of uninitialized value $msg in pattern match (m//) at ./FHEM/00_CUL.pm line 135.
ERROR: dutycycle not 0-range (default 255)
-8
ERROR: dutycycle not 0-range (default 255)
-8
ERROR: dutycycle not 0-range (default 255)
-8
ERROR: dutycycle not 0-range (default 255)
-8
ERROR: dutycycle not 0-range (default 255)
-8
ERROR: dutycycle not 0-range (default 255)
-8
ERROR: dutycycle not 0-range (default 255)
-8
ERROR: dutycycle not 0-range (default 255)
-8
ERROR: dutycycle not 0-range (default 255)
-8
ERROR: dutycycle not 0-range (default 255)
-8
ERROR: dutycycle not 0-range (default 255)
-8
ERROR: dutycycle not 0-range (default 255)
-8
ERROR: dutycycle not 0-range (default 255)
-8
ERROR: dutycycle not 0-range (default 255)
-8
ERROR: dutycycle not 0-range (default 255)
-8
ERROR: dutycycle not 0-range (default 255)
-8
ERROR: dutycycle not 0-range (default 255)
-8
ERROR: dutycycle not 0-range (default 255)
-8
ERROR: dutycycle not 0-range (default 255)
-8
ERROR: dutycycle not 0-range (default 255)
-8
ERROR: dutycycle not 0-range (default 255)
-8
ERROR: dutycycle not 0-range (default 255)
-8
ERROR: dutycycle not 0-range (default 255)
-8
ERROR: dutycycle not 0-range (default 255)
-8
ERROR: dutycycle not 0-range (default 255)
-8
ERROR: dutycycle not 0-range (default 255)
-8
ERROR: dutycycle not 0-range (default 255)
-8
ERROR: dutycycle not 0-range (default 255)
-8
ERROR: dutycycle not 0-range (default 255)
-8
ERROR: dutycycle not 0-range (default 255)
-8
ERROR: dutycycle not 0-range (default 255)
-8
ERROR: dutycycle not 0-range (default 255)
-8
ERROR: dutycycle not 0-range (default 255)
-8
ERROR: dutycycle not 0-range (default 255)
-8
ERROR: dutycycle not 0-range (default 255)
-8
ERROR: dutycycle not 0-range (default 255)
-8
ERROR: dutycycle not 0-range (default 255)
-8
ERROR: dutycycle not 0-range (default 255)
-8
ERROR: dutycycle not 0-range (default 255)
-8
ERROR: dutycycle not 0-range (default 255)
-8
ERROR: dutycycle not 0-range (default 255)
-8
ERROR: dutycycle not 0-range (default 255)
-8
ERROR: dutycycle not 0-range (default 255)
-8
ERROR: dutycycle not 0-range (default 255)
-8
ERROR: dutycycle not 0-range (default 255)
-8
ERROR: dutycycle not 0-range (default 255)
-8
ERROR: dutycycle not 0-range (default 255)
-8
2015.12.24 12:53:17 2: MAX MaxScan: UtilsMaxScan_Initialize.86 MaxScan is starting
2015.12.24 12:53:17 5: Initializing Type Library:
2015.12.24 12:53:17 1: Including fhem.cfg
2015.12.24 12:53:17 5: Cmd: >attr global userattr cmdIcon devStateIcon devStateStyle fm_fav fm_groups fm_name fm_order fp_Grundriss icon sortby structexclude webCmd widgetOverride<
2015.12.24 12:53:17 5: Cmd: >attr global autoload_undefined_devices 1<
2015.12.24 12:53:17 5: Cmd: >attr global logfile ./log/fhem/fhem-%Y-%m.log<
2015.12.24 12:53:17 5: Cmd: >attr global modpath .<
2015.12.24 12:53:17 5: Cmd: >attr global statefile ./log/fhem.save<
2015.12.24 12:53:17 5: Cmd: >attr global updateInBackground 1<
2015.12.24 12:53:17 5: Cmd: >attr global verbose 5<
2015.12.24 12:53:17 5: Cmd: >define telnetPort telnet 7072 global<
2015.12.24 12:53:17 5: Loading ./FHEM/98_telnet.pm
Für mich ist es nicht ganz klar erkennbar, ab wann hier der Reboot erfolgt - vermutlich ab MaxScan -> Die vorhergehenden Errors könnten also das Problem sein.
Nur was sagen diese aus?
Stimmt es, das Deine Instanz nur 3! Minuten gelaufen ist?
Es könnte sein, dass die entsprechenden Meldungen:
-8
ERROR: dutycycle not 0-range (default 255)
aus der C-Lib pigpio stammen --> https://github.com/joan2937/pigpio (https://github.com/joan2937/pigpio)
Diese stellt auch PWM-Funktionen an den GPIO Pins bereit, dabei sind keine Werte ausserhalb von 0-255 erlaubt.
Nicht sicher ob Du damit den Verursacher identifizieren kannst.
Hallo viegener,
dem Tipp werde ich auf jeden Fall mal nachgehen. Ich nutze pigpio tatsächlich zur Ansteuerung von PWM Transistoren, zur Steuerung meines LED Streifens.
Allerdings habe ich die Scripte schon vor FHEM so in der Form genutzt und nie Probleme gehabt.
Zwei Gedanken:
Wenn dies der Grund des FHEM Absturzes ist, dann kann es nur im Moment eines offenen Fensters sein. (Benachrichtigung das Fenster zu lange offen). Dann allerdings käme auch keine Bestätigung das Fenster geschlossen wurde. - Ich habe bisher nie einen Absturz zwischen Fenster geöffnet und wieder geschlossen gehabt. -
Ebenfalls wird ein Blinken ausgelöst, wenn ein Telefonanruf eingeht - aber auch hier bisher keine Parallelen....
Zitat von: Kharim am 27 Dezember 2015, 08:46:26
Zwei Gedanken:
Wenn dies der Grund des FHEM Absturzes ist, dann kann es nur im Moment eines offenen Fensters sein. (Benachrichtigung das Fenster zu lange offen). Dann allerdings käme auch keine Bestätigung das Fenster geschlossen wurde. - Ich habe bisher nie einen Absturz zwischen Fenster geöffnet und wieder geschlossen gehabt. -
Ebenfalls wird ein Blinken ausgelöst, wenn ein Telefonanruf eingeht - aber auch hier bisher keine Parallelen....
Ich kann nicht unbedingt sagen, ob die Fehlermeldungen den Absturz verursachen, sie erscheinen nur relativ kurz vor dem Neustart und kommen nicht direkt aus FHEM. Ausserdem erscheinen sie gravierend genug, um zu vermuten, dass es einen Absturz verursachen könnte. Wobei noch nicht erklärt ist, warum FHEM dann neu startet?
Soooo,
also es war wirklich ein Fehler in meinem pigpio-Script. Unter bestimmten Umständen wurde wirklich versucht Werte über 255 zu setzen.
Dies ist nun behoben. - mal sehen ob/was das nächste Absturz-Log sagt.
Warum "FHEM neu startet" kann ich dir sagen:
Ich überwache auf Linux-Ebene alle 5 Minuten die Dienste, ob diese noch vorhanden sind. Fehlt hier der FHEM Dienst wird pauschal das PI neu gestartet und damit dann auch FHEM.
((( Die Error Meldung kam nachvollziehbar bei jedem Aufblinken des LED Bandes - wäre es der Absturzgrund, müsste FHEM bei Blinken der LEDs sterben - tut es aber nicht...es wird bei Fenster schließen korrekt das Blinken unterbrochen etc....."irgendwas" danach muss noch passiert sein.)))
Gut, dann ist zumindest ein Fehler behoben ;)
und klar, das hatte ich angenommen, dass da irgendeine Überwachung läuft und nicht irgendetwas Amok läuft...
Wenn es nicht der Grund für den Absturz ist, dann ist weitersuchen angesagt...
Guten Morgen Zusammen,
Ich glaube diese Nacht war der Teufel los.....mein Pi hat laut E-Mail Benachrichtigung und zugehörigem Log 6 Mal in kurzer Zeit neu gestartet.
Eigenartiger Weise ist das FHEM Log zu dieser Zeit leer.....
2015.12.28 21:18:17 5: exec at command CreditsScript
2015.12.28 21:18:17 5: Cmd: >{my $value=fhem("get Cube credit10ms");;fhem("set aktCredits $value")}<
2015.12.28 21:18:17 5: Cmd: >get Cube credit10ms<
2015.12.28 21:18:17 3: get Cube credit10ms : Cube credit10ms => 1681
2015.12.28 21:18:17 5: Cmd: >set aktCredits Cube credit10ms => 1681<
2015.12.28 21:18:17 4: dummy set aktCredits Cube credit10ms => 1681
2015.12.28 21:18:17 5: Triggering aktCredits (1 changes)
2015.12.28 21:18:17 5: Notify loop for aktCredits Cube credit10ms => 1681
2015.12.28 21:18:17 5: redefine at command CreditsScript as +*00:05:00 {my $value=fhem("get Cube credit10ms");;fhem("set aktCredits $value")}
2015.12.28 21:44:37 2: MAX MaxScan: UtilsMaxScan_Initialize.86 MaxScan is starting
2015.12.28 21:44:37 5: Initializing Type Library:
2015.12.28 21:44:37 1: Including fhem.cfg
2015.12.28 21:44:37 5: Cmd: >attr global userattr cmdIcon devStateIcon devStateStyle fm_fav fm_groups fm_name fm_order fp_Grundriss icon sortby structexclude webCmd widgetOverride<
2015.12.28 21:44:37 5: Cmd: >attr global autoload_undefined_devices 1<
2015.12.28 21:44:37 5: Cmd: >attr global logfile ./log/fhem/fhem-%Y-%m.log<
2015.12.28 21:44:37 5: Cmd: >attr global modpath .<
2015.12.28 21:44:37 5: Cmd: >attr global motd Error messages while initializing FHEM:
statefile: ProgrammBad
ProgrammBad
ProgrammBad
ProgrammKinderzimmer
ProgrammKinderzimmer
ProgrammKinderzimmer
ProgrammKueche
ProgrammKueche
ProgrammKueche
ProgrammWohnzimmer
ProgrammWohnzimmer
ProgrammWohnzimmer<
2015.12.28 21:44:37 5: Cmd: >attr global statefile ./log/fhem.save<
2015.12.28 21:44:37 5: Cmd: >attr global updateInBackground 1<
2015.12.28 21:44:37 5: Cmd: >attr global verbose 5<
Reboot-Log:
Mo 28. Dez 21:20:01 CET 2015 FHEM-Reboot
Mo 28. Dez 21:23:01 CET 2015 FHEM-Reboot
Mo 28. Dez 21:26:01 CET 2015 FHEM-Reboot
Mo 28. Dez 21:29:01 CET 2015 FHEM-Reboot
Mo 28. Dez 21:32:01 CET 2015 FHEM-Reboot
Mo 28. Dez 21:35:01 CET 2015 FHEM-Reboot
Mo 28. Dez 21:38:01 CET 2015 FHEM-Reboot
Mo 28. Dez 21:41:01 CET 2015 FHEM-Reboot
Mo 28. Dez 21:44:01 CET 2015 FHEM-Reboot
(Das Script auf Systemebene prüft alle 5 Minuten ob der FHEM Dienst noch läuft (CronJob alle 3 Minuten + 2 Minuten Wartezeit im Script zur Vermeidung einer Rebootschleife))
Klar, die Vermutung liegt nahe, dass FHEM gar nicht erst gestartet wurde....fragt sich nur warum und wieso der erste Absturz entstand.....
Klingt nicht gut.
Da der log file weiterhin nichts hergibt fängt jetzt vermutlich eine grössere Suche an. Vorschläge:
- Sagt /var/log/syslog irgendetwas (vielleicht auch alte Dateien .1 etc)?
- Übertaktung? Wenn ja runterdrehen auf Standard
- Netzteil austauschen? Klingt banal, aber kann immer Einfluss auf die Stabilität des PI haben (normalerweise allerdings nicht auf einen einzelnen Prozess)
- Bist Du sicher, dass Dein Überwachungsskript nicht Amok läuft und nur annimmt FHEM läuft nicht mehr?
Dann würde ich anfangen Ursachen in FHEM auszuschliessen:
- Alle nicht zum Betrieb absolut notwendigen Teile von FHEM zeitweise inaktivieren -> Damit Du einen Basisstand hast, der notwendig ist und dann sehen kannst ob davon etwas Probleme macht (z.B. SYSMON?)
- Teile, die externe Programme oder Libraries nutzen sind per se eher verdächtig, da u.U. bei Problemen keine Rückmeldung an FHEM/Perl mehr ankommt (wie bei Dir) --> Diese würde ich wenn möglich zeitweise deaktivieren
Wie gesagt Stochern im Dunkeln, das sind Ansatzpunkte. Viel Glück bei der Suche!
yepp. Und starte mal fhem von Hand über eine console und warte ab (Console offen lassen, logisch oder?). Den reboot deaktivieren - sonst siehste nix ;)
Wenn fhem stirbt wirst Du da einen Fehlermeldung sehen.
vg
joerg
Hallo Zusammen,
- Sagt /var/log/syslog irgendetwas (vielleicht auch alte Dateien .1 etc)?
-> Nicht wirklich - man sieht nur die regelmäßige Überprüfung der Dienste.
-> Erstaunlicher Weise hat es aber wirklich nur einen Reboot gegeben - den letzten Eintrag. Keine Ahnung warum die vorhergehenden Reboot- Befehle ignoriert wurden.
(Log im Anhang)
- Übertaktung? Wenn ja runterdrehen auf Standard
Nein
- Netzteil austauschen? Klingt banal, aber kann immer Einfluss auf die Stabilität des PI haben (normalerweise allerdings nicht auf einen einzelnen Prozess)
Bereits zweimal geschehen. (Zu Anfang komplett Abstürze des Raspi - Seit Netzteiltausch geschichte...)
- Bist Du sicher, dass Dein Überwachungsskript nicht Amok läuft und nur annimmt FHEM läuft nicht mehr?
(siehe Syslog) Ich sage es mal so...wenn das Script läuft, habe ich "keine Ausfälle" der Webseite - läuft es nicht, habe ich früher oder später keinen Zugriff/FHEM mehr.
Wie weiter oben geschrieben ist ja nachweislich der FHEM Dienst weg.
Zur Vollständigkeit hier mal die 3 Zeilen Code:
sleep 2m
if [ $(ps -ax | grep -c fhem) -lt 2 ];
then
echo "$(date) FHEM-Reboot" >> /xxx/Ueberwachung/log
sendEmail -f xxx@xxx.de -t xxxx@xxx.de -u RaspiReboot $
#sudo reboot
fi
if [ $(ps -A | grep -c pigpiod) = 0 ];
then
echo "$(date) Pigpiod-Reboot" >> /xxx/Ueberwachung/log
sendEmail -f xxx@xxx.de -t xxxx@xxx.de -u RaspiReboot $
#sudo reboot
fi
Dann würde ich anfangen Ursachen in FHEM auszuschliessen:
- Alle nicht zum Betrieb absolut notwendigen Teile von FHEM zeitweise inaktivieren -> Damit Du einen Basisstand hast, der notwendig ist und dann sehen kannst ob davon etwas Probleme macht (z.B. SYSMON?)
- Teile, die externe Programme oder Libraries nutzen sind per se eher verdächtig, da u.U. bei Problemen keine Rückmeldung an FHEM/Perl mehr ankommt (wie bei Dir) --> Diese würde ich wenn möglich zeitweise deaktivieren
Ich kann gerne mal alles "überflüssige" deaktivieren, glaube aber nicht das es von einem externen Programm kommt.
Die Probleme traten schon vor Sysmon auf. Ein Absturz erfolgte bisher nie nach einer Nutzeraktion, die wiederum etwas externes anstößt, sondern immer "in Ruhe". Sprich wenn das FHEM nur überwacht....
Und starte mal fhem von Hand über eine console und warte ab (Console offen lassen, logisch oder?). Den reboot deaktivieren - sonst siehste nix ;)
Wenn fhem stirbt wirst Du da einen Fehlermeldung sehen.
Den Gedanken hatte ich auch schon. Reboot ist deaktiviert und FHEM über die Konsole gestartet....aber:
- Somit muss ich FHEM mit dem Linux-Nutzer starten - nicht mit dem fhem Nutzer -> Zugriffsprobleme auf sämtliche Log Dateien -> Start per sudo und somit unter veränderten Rechten!
- Ich glaube noch nicht so recht, dass ich etwas in der Konsole sehen werde -> (wie schreib ich das jetzt am besten?) Der Prozess bleibt nicht im FHEM, sondern springt zurück in die Eingabe....äh...Screenshot ;-)
(Hätte gedacht da jetzt Logeinträge etc zur Laufzeit zu sehen.)
Ich werde aber nach dem nächsten Absturz mal versuchen dann per Konsole FHEM zu starten - vieleicht gibt das ja einen Fehler.....
Danke soweit,
Kharim
Ich denke mit von hand über die konsole war nicht der init.d aufruf sondern der perl aufruf, der sich in deinem init.d skript befindet geadcht. Und ja natürlich sollte das unter dem fhem benutzer passieren also über su oder sudo su den benutzer wechseln.
Es geht ja darum herauszufinden ob im terminal eine meldung erscheint, die nur bei einem vordergrundprozess zu sehen ist
Sorry ich muss nochmal dumm nachfragen:
Ein "sudo perl fhem.pl fhem.cfg" als Standart-Nutzer verhällt sich genauso, wie ein Start über init.d....
Wie starte ich das nun als fhem Nutzer?
Ein "su fhem" verlangt (logischer Weise) nach dem Passwort von fhem...was ich aber hab niemals festgelegt und bisher auch kein standart Passwort gefunden habe ??!
P.S.: Nach Absturz des FHEM lässt sich dieses auch ohne Reboot problemlos neu starten....
Schonmal einen guten Rutsch Morgen, kommt gut ins neue Jahr!
Kharim
Paswort von FHEM ... ist doch einfach:
passwd fhem
Natürlich mit enstprechenden Rechten, d.h. als root oder mit sudo
Mit sudo geht auch sudo su fhem, wie oben erwähnt ;)