FHEM stürzt ab

[vossi]

Hallo Forum,

ich beschäftige mich erst seit Kurzem mit FHEM, nehmt mir meine Ahnungslosigkeit also bitte nicht übel.
Aber ich habe ein Problem. FHEM läuft bei mir auf einer FB7390, stürzt aber ab, wenn ich in der Web-Ansicht (Port 8083) zu viel hin und her klicke. Über die anderen Ports (8084 und 8085) ist FHEM noch erreichbar, auf 8083 läuft die Eieruhr ewig. Lösung:FHEM beenden (per Telnet) und neu starten.

Ach ja: FHEM ist bei mir via Download-Image von fhem.de installiert, nicht die AVM-Version.

Im Log steht nach so einer Aktion nix darüber drin. Gibt es zusätzliche Infos, die weiterhelfen?
Ist schon störend und kann ja eigentlich nicht der Regelfall sein...
Jörg

[torsten31j]

Hi, ich habe bei mir das gleiche Problem. Hat jemand eine Lösung ?

Bye Torsten

[myfhem41113]

Ja, habe ich auch immer wieder. Weiss leider bisher keine Lösung ausser per LAN-Überwachung (nmap auf Port 8083) bei Eintritt des Absturzes eine eMail zu bekommen.

Code Auswählen Erweitern

#FHEM aktiv ?
nmap -v -p T:8083 fritz.box |grep Discovered > /dev/null 2> /dev/null
if [ $? -eq 0 ]; then
        echo ">>> FHEM aktiv - passt <<<"
else
        echo ">>> ACHTUNG: FHEM deaktiviert !<<<"
        nmap -v -p T:8083 fritz.box |grep closed >> $FHEM
        /usr/bin/watchMYmail2.sh
fi



[rudolfkoenig]

Steht was darueber im Log?

[myfhem41113]

Hallo Rudolf,

mein LANWATCHER hat folgendes festgestellt:

Code Auswählen Erweitern

Mi 13. Nov 07:15:36 CET 2013: >>> ACHTUNG: FHEM deaktiviert !!! <<<
8083/tcp closed us-srv


Im Log steht dazu folgendes:

2013.11.13 07:15:00 2: EIB set RolloBadEG on
2013.11.13 07:15:01 2: EIB set RolloFlurEG on
2013.11.13 07:15:02 2: EIB set RolloKuecheTuer on
2013.11.13 07:15:03 2: EIB set RolloSpeis on
2013.11.13 07:15:04 2: EIB set RolloSN on
2013.11.13 07:15:05 2: EIB set RolloSOst on
2013.11.13 07:15:05 2: EIB set RolloWohnziFenster on
2013.11.13 07:15:06 2: EIB set RolloWohnziFluegeltuere on
2013.11.13 07:15:07 2: EIB set RolloWohnziTuer on
2013.11.13 07:15:08 2: EIB set RollosKueche on
2013.11.13 07:15:09 3: Control Byte 0x81 does not match expected mask 0xB0
2013.11.13 07:15:09 3: TUL tul refused message: 81d68bbc110e1402e100812abc09f90106e10081d4
2013.11.13 07:15:10 2: EIB RolloWohnziFenster on
2013.11.13 07:15:11 3: Control Byte 0x8b does not match expected mask 0xB0
2013.11.13 07:15:11 3: TUL tul refused message: 8bbc09f90009e10081da8bbc09f9000d
2013.11.13 07:15:11 3: Control Byte 0x00 does not match expected mask 0xB0
2013.11.13 07:15:11 3: TUL tul refused message: 0081de8bbc09f90013e10081c08bbc11
2013.11.13 07:15:14 3: Control Byte 0x1a does not match expected mask 0xB0
2013.11.13 07:15:14 3: TUL tul refused message: 1a08e100816abc110e1402e100812abc11
2013.11.13 07:15:24 3: Control Byte 0x14 does not match expected mask 0xB0
2013.11.13 07:15:24 3: TUL tul refused message: 1402e100812abc110e1402e100812abc11
2013.11.13 07:15:29 3: Control Byte 0x14 does not match expected mask 0xB0
2013.11.13 07:15:29 3: TUL tul refused message: 1402e100812abc11401805e20080006d9c
2013.11.13 07:15:29 1: tul:/dev/ttyACM0 disconnected, waiting to reappear
2013.11.13 08:04:47 1: Including fhem.cfg
2013.11.13 08:04:49 3: telnetPort: port 7072 opened
2013.11.13 08:04:51 3: WEB: port 8083 opened
2013.11.13 08:04:51 3: WEBphone: port 8084 opened
2013.11.13 08:04:51 3: WEBtablet: port 8085 opened
2013.11.13 08:04:52 3: TUL opening tul device tul:/dev/ttyACM0
2013.11.13 08:04:53 3: TUL setting tul baudrate to 19200
2013.11.13 08:04:53 3: TUL device opened
2013.11.13 08:04:53 2: Unsupported method TUL_Attr(set,tul,icon,cul)
2013.11.13 08:05:04 1: Including ./log/fhem.save
2013.11.13 08:05:06 1: statefile: Undefined value 0c5a

Um 7:15 soll er die Rollos im EG hochfahren. Der Neustart der Fritzbox erfolgte dann um 8 Uhr.

[rudolfkoenig]

Ich sehe keine verstaendlichen Meldungen, evtl. schliesst ein anderes Modul die FHEM-Instanz (sehr komisch). Sowas koennte man zwar mit verbose 5 sehen, aber das kann man nur einschalten, wenn man genau weiss, wann das Problem auftritt.

[myfhem41113]

Hier wieder der aktuelle Fall:

2013.11.15 16:30:00 2: EIB set RolloBadEG off
2013.11.15 16:30:01 2: EIB set RolloFlurEG off
2013.11.15 16:30:02 2: EIB set RolloKuecheTuer off
2013.11.15 16:30:04 2: EIB set RolloSpeis off
2013.11.15 16:30:05 2: EIB set RolloStefanN off
2013.11.15 16:30:06 2: EIB set RolloStefanOst off
2013.11.15 16:30:07 2: EIB set RolloWohnziFenster off
2013.11.15 16:30:09 2: EIB set RolloWohnziTuer off
2013.11.15 16:30:10 2: EIB set RollosKueche off
2013.11.15 16:30:11 2: EIB set RolloBad off
2013.11.15 16:30:12 2: EIB set RolloBuero off
2013.11.15 16:30:12 2: EIB set RolloHeizung off
2013.11.15 16:30:12 2: EIB set RolloWerkstatt off
2013.11.15 16:30:14 3: Control Byte 0x03 does not match expected mask 0xB0
2013.11.15 16:30:14 3: TUL tul refused message: 0306e10080d78bbc09f90304e100
2013.11.15 16:30:14 1: tul:/dev/ttyACM0 disconnected, waiting to reappear

[rudolfkoenig]

Ich sehe nichts neues, und das Gleiche zu wiederholen hilft auch nicht.
Da mit dem USB-Stick offensichtlich Probleme gibt, sollte man evtl. da weiterforschen.

Vielleicht kann man in der FHEM KNX/EIB Gruppe mit der Meldung was anfangen.

[myfhem41113]

Hallo Rudi,
habe den Eindruck wenn auf dem BUS schnell hintereinander gesendet wird, dass es dann den TUL wirft.

Hier das Logfile mit VERBOSE 5:

2013.11.16 14:41:46 4: tul: B1138w140601
2013.11.16 14:41:46 5: tul dispatch B1138w140601
2013.11.16 14:41:46 2: EIB LampeFlur on
2013.11.16 14:41:46 5: Triggering LampeFlur (1 changes)
2013.11.16 14:41:46 5: Notify loop for LampeFlur on
2013.11.16 14:41:46 5: Update structure 'LichtAlleKG' to undefined because device LampeFlur has changed
2013.11.16 14:41:46 5: Triggering LichtAlleKG (3 changes)
2013.11.16 14:41:46 5: Notify loop for LichtAlleKG LastDevice: LampeFlur
2013.11.16 14:41:46 5: SET: Unknown argument ?, choose one of off on on-for-timer on-till raw value
Unknown argument ?, choose one of off on on-for-timer on-till raw value
Unknown argument ?, choose one of off on on-for-timer on-till raw value
Unknown argument ?, choose one of off on on-for-timer on-till raw value
Unknown argument ?, choose one of off on on-for-timer on-till raw value
Unknown argument ?, choose one of off on on-for-timer on-till raw value
Unknown argument ?, choose one of off on on-for-timer on-till raw value
Unknown argument ?, choose one of off on on-for-timer on-till raw value
Unknown argument ?, choose one of off on on-for-timer on-till raw value
2013.11.16 14:41:46 5: Triggering NLampeFlurKG
2013.11.16 14:41:46 5: Cmd: >{if (isday()) { fhem("set LampeFlur off") } }<
2013.11.16 14:41:47 5: Compute sunrise/sunset for latitude 48.514899 , longitude 13.373365
2013.11.16 14:41:47 5: Cmd: >set LampeFlur off<
2013.11.16 14:41:47 2: EIB set LampeFlur off
2013.11.16 14:41:47 5: tul sending Bw140600
2013.11.16 14:41:47 5: encode_tpuart dst: 1406 apci: 2 datalen: 1 data: 0
2013.11.16 14:41:47 5: SendGroup: dst: 1406, msg: 128 188 129 9 130 249 131 12 132 6 133 225 134 0 135 128 72 216

2013.11.16 14:41:47 5: sendRequest: 80bc810982f9830c840685e18600878048d8

2013.11.16 14:41:47 5: waiting to receive 10 bytes ...
2013.11.16 14:41:47 5: Received fixlen packet: bc11010c07e1008138

2013.11.16 14:41:47 5: Received fixlen packet: bc

2013.11.16 14:41:47 5: getRequest len: 10 packet: bc11010c07e1008138bc

2013.11.16 14:41:47 5: Triggering LampeFlur (1 changes)
2013.11.16 14:41:47 5: waiting to receive 8 bytes ...
2013.11.16 14:41:47 5: Received fixlen packet: 09f90c06e10080d8

2013.11.16 14:41:47 5: getRequest len: 8 packet: 09f90c06e10080d8

2013.11.16 14:41:47 5: receiving telegram with len: 8
2013.11.16 14:41:47 5: Telegram: (7): 09f90c06e10080
2013.11.16 14:41:47 5: Buf: (0):
2013.11.16 14:41:47 3: Control Byte 0x09 does not match expected mask 0xB0
2013.11.16 14:41:47 4: No data received.
2013.11.16 14:41:47 3: TUL tul refused message: 09f90c06e10080
2013.11.16 14:41:47 5: waiting to receive 8 bytes ...
2013.11.16 14:41:47 5: Received fixlen packet: 8b

2013.11.16 14:41:47 5: Received fixlen packet: bc

2013.11.16 14:41:47 5: Received fixlen packet: 11010c07e100

2013.11.16 14:41:47 5: getRequest len: 8 packet: 8bbc11010c07e100

2013.11.16 14:41:47 5: receiving telegram with len: 15
2013.11.16 14:41:47 5: waiting to receive 7 bytes ...
2013.11.16 14:41:47 5: Received fixlen packet: 8039

2013.11.16 14:41:47 5: Received fixlen packet: bc

2013.11.16 14:41:47 5: Received fixlen packet: 110e1402

2013.11.16 14:41:47 5: getRequest len: 7 packet: 8039bc110e1402

2013.11.16 14:41:47 5: receiving telegram with len: 15
2013.11.16 14:41:47 5: Telegram: (14): 8bbc11010c07e1008039bc110e14
2013.11.16 14:41:47 5: Buf: (0):
2013.11.16 14:41:47 3: Control Byte 0x8b does not match expected mask 0xB0
2013.11.16 14:41:47 4: No data received.
2013.11.16 14:41:47 3: TUL tul refused message: 8bbc11010c07e1008039bc110e14
2013.11.16 14:41:47 5: waiting to receive 8 bytes ...
2013.11.16 14:41:47 5: Received fixlen packet: e100812a

2013.11.16 14:41:52 5: Received fixlen packet: bc

2013.11.16 14:41:52 5: Received fixlen packet: 11380c

2013.11.16 14:41:52 5: getRequest len: 8 packet: e100812abc11380c

2013.11.16 14:41:52 5: TPUART RSP 0xe1 ignored.
2013.11.16 14:41:52 4: No data received.
2013.11.16 14:41:52 1: tul:/dev/ttyACM0 disconnected, waiting to reappear
2013.11.16 14:41:57 5: Triggering tul (1 changes)
2013.11.16 14:41:57 5: Notify loop for tul DISCONNECTED
2013.11.16 14:41:57 3: TUL setting tul baudrate to 19200
2013.11.16 14:41:57 1: TUL tul:/dev/ttyACM0 reappeared (tul)
2013.11.16 14:41:57 5: purging receiver buffer
2013.11.16 14:41:57 5: purging packet: bc010c07e1008138bc0e1402e100812a47474747474747474747474747

2013.11.16 14:41:57 5: Triggering tul (1 changes)
2013.11.16 14:41:57 5: Notify loop for tul CONNECTED
2013.11.16 14:41:57 5: waiting to receive 8 bytes ...
2013.11.16 14:41:57 5: Received fixlen packet: bc110e1402e10081

2013.11.16 14:41:57 5: getRequest len: 8 packet: bc110e1402e10081

2013.11.16 14:41:57 5: receiving telegram with len: 9
2013.11.16 14:41:57 5: waiting to receive 1 bytes ...
2013.11.16 14:41:57 5: Received fixlen packet: 2a

2013.11.16 14:41:57 5: getRequest len: 1 packet: 2a

2013.11.16 14:41:57 5: receiving telegram with len: 9
2013.11.16 14:41:57 5: Telegram: (: bc110e1402e10081
2013.11.16 14:41:57 5: Buf: (0):
2013.11.16 14:41:57 5: msg cmd: 0x81 datalen: 2
2013.11.16 14:41:57 5: msg cmd: 0x81 datalen: 2 apci: 2
2013.11.16 14:41:57 5: decode_tpuart byte len: 1 array size: 1
2013.11.16 14:41:57 5: SimpleRead msg.type: write, msg.src: 110e, msg.dst: 2402
2013.11.16 14:41:57 5: SimpleRead data: 01
2013.11.16 14:41:57 4: SimpleRead: B110ew240201

2013.11.16 14:41:57 4: tul: B110ew240201
2013.11.16 14:41:57 5: tul dispatch B110ew240201
2013.11.16 14:41:57 2: EIB Garagentor on
2013.11.16 14:41:57 5: Triggering Garagentor (1 changes)
2013.11.16 14:41:57 5: Notify loop for Garagentor zu
2013.11.16 14:42:02 5: waiting to receive 8 bytes ...
2013.11.16 14:42:02 5: Received fixlen packet: bc110e1402e1

2013.11.16 14:42:02 5: Received fixlen packet: 0081

2013.11.16 14:42:02 5: getRequest len: 8 packet: bc110e1402e10081

2013.11.16 14:42:02 5: receiving telegram with len: 9
2013.11.16 14:42:02 5: waiting to receive 1 bytes ...
2013.11.16 14:42:02 5: Received fixlen packet: 2a

2013.11.16 14:42:02 5: getRequest len: 1 packet: 2a

2013.11.16 14:42:02 5: receiving telegram with len: 9
2013.11.16 14:42:02 5: Telegram: (: bc110e1402e10081
2013.11.16 14:42:02 5: Buf: (0):
2013.11.16 14:42:02 5: msg cmd: 0x81 datalen: 2
2013.11.16 14:42:02 5: msg cmd: 0x81 datalen: 2 apci: 2
2013.11.16 14:42:02 5: decode_tpuart byte len: 1 array size: 1
2013.11.16 14:42:02 5: SimpleRead msg.type: write, msg.src: 110e, msg.dst: 2402
2013.11.16 14:42:02 5: SimpleRead data: 01
2013.11.16 14:42:02 4: SimpleRead: B110ew240201

2013.11.16 14:42:02 4: tul: B110ew240201
2013.11.16 14:42:02 5: tul dispatch B110ew240201

[rudolfkoenig]

Ich habe das mal nach KNX/EIB verschoben, vielleicht koennen die KNX Experten was dazu sagen.

[myfhem41113]

Hier der heutige Absturz. Schön langsam nervt das ...

2013.11.23 07:45:10 3: Control Byte 0x36 does not match expected mask 0xB0
2013.11.23 07:45:10 3: TUL tul refused message: 36bc09f90007e10081d48bbc1102
2013.11.23 07:45:10 3: Control Byte 0x0b does not match expected mask 0xB0
2013.11.23 07:45:10 3: TUL tul refused message: 0be10081369c11020d0be10081169c11020d0b
2013.11.23 07:45:10 3: Control Byte 0x00 does not match expected mask 0xB0
2013.11.23 07:45:10 3: TUL tul refused message: 0081169c11020d0be1
2013.11.23 07:45:10 3: Control Byte 0x81 does not match expected mask 0xB0
2013.11.23 07:45:10 3: TUL tul refused message: 8116bc11020d01e100813c9c11020d01e100811c
2013.11.23 07:45:10 3: Control Byte 0x11 does not match expected mask 0xB0
2013.11.23 07:45:10 3: TUL tul refused message: 11020d01e10081
2013.11.23 07:45:10 3: Control Byte 0x9c does not match expected mask 0xB0
2013.11.23 07:45:10 3: TUL tul refused message: 9c11020d01e10081
2013.11.23 07:45:10 2: EIB RolloSpeis on
2013.11.23 07:45:11 3: Control Byte 0x8b does not match expected mask 0xB0
2013.11.23 07:45:11 3: TUL tul refused message: 8bbc09f90104e10081d68b
2013.11.23 07:45:11 3: Control Byte 0x09 does not match expected mask 0xB0
2013.11.23 07:45:11 3: TUL tul refused message: 09f90106e10081
2013.11.23 07:45:11 3: Control Byte 0x8b does not match expected mask 0xB0
2013.11.23 07:45:11 3: TUL tul refused message: 8bbc09f9000be10081d88bbc11441903e300
2013.11.23 07:45:11 3: Control Byte 0x0c does not match expected mask 0xB0
2013.11.23 07:45:11 3: TUL tul refused message: 0c2f4c9c11441903e30080
2013.11.23 07:45:11 3: Control Byte 0x2f does not match expected mask 0xB0
2013.11.23 07:45:11 3: TUL tul refused message: 2f6c9c11441903e300800c2f6c9c1144
2013.11.23 07:45:11 3: Control Byte 0x03 does not match expected mask 0xB0
2013.11.23 07:45:11 3: TUL tul refused message: 03e300800c2f6cbc09f90009e10081da8bbc110e1402
2013.11.23 07:45:12 3: Control Byte 0x00 does not match expected mask 0xB0
2013.11.23 07:45:12 3: TUL tul refused message: 00812abc09f9000de10081de8bbc09f9
2013.11.23 07:45:14 3: Control Byte 0x13 does not match expected mask 0xB0
2013.11.23 07:45:14 3: TUL tul refused message: 13e10081c08bbc110e1402e100812abc1141
2013.11.23 07:45:14 3: Control Byte 0x07 does not match expected mask 0xB0
2013.11.23 07:45:14 3: TUL tul refused message: 07e20080006e9c11411807e20080004e9c11411807
2013.11.23 07:45:14 3: Control Byte 0x00 does not match expected mask 0xB0
2013.11.23 07:45:14 3: TUL tul refused message: 0080004e9c114118

[myfhem41113]

Hallo,
so wie es aussieht hängt es mit meiner Fritzbox zusammen auf der FHEM läuft.

Wenn ein Logfile von FHEM recht groß wird ( > 800KB) kommen die Abstürze.

Habe es damit gelöst, dass das normale FHEM-Logfile statt monatlich jetzt wöchentlich erstellt wird. Die anderen Logfiles werden bei mir nicht so groß.

Code Auswählen Erweitern


attr global logfile ./log/fhem-%Y-%m-%W.log