FHEM hängt sich weg bei at +00:01:00 watchdog

AK-868 · 02 August 2013, 22:58:24

Immer wenn eine Aktion passieren soll durch ein at oder anderes hängt sich das komplette fhem auf.

Teilweise verliert er sogar die verbindung zum HMLAN. In den Logs steht leider nichts.

Oft ist es nach ablauf der Zeit das es weiterläuft. Oft hängt es sich aber komplett auf.

Hat jemand idee wie ich dem auf dem Grund gehen kann?

Gruß
Andre

Puschel74 · 03 August 2013, 08:34:49

Hallo,

was steht im Logfile (bitte nur die letzten Zeilen kurz vor dem "hängt sich auf").

Ich hab bei mir einige at`s am laufen und fhem ist das egal.

Grüße

AK-868 · 06 August 2013, 22:04:19

Mein Problem ist das sich Probleme häufen. Ich habe versucht ein Muster zu erkennen, leider Erfolglos.

In den Logs stand leider nichts dazu. Was jetzt zusätzlich noch passiert sind mal wieder HMLAN disconnects.

Ebenfalls ohne Logeinträge vorher.

Hier ein kurzer Auszug. Er war über 30min grundlos weg.

2013.08.06 19:56:49 2: CUL_HM set sw_TVAnlage on
2013.08.06 19:56:49 2: CUL_HM set sw_Subwoofer on
2013.08.06 19:56:49 3: Yamaha definiert, AV und eingeschaltet
2013.08.06 20:29:55 1: 192.168.0.2:1000 disconnected, waiting to reappear
2013.08.06 20:29:55 1: 192.168.0.2:1000 reappeared (HMLAN1)
2013.08.06 20:29:59 2: HMLAN_Parse: HMLAN1 new condition ok
2013.08.06 21:07:31 1: 192.168.0.2:1000 disconnected, waiting to reappear
2013.08.06 21:07:33 1: 192.168.0.2:1000 reappeared (HMLAN1)
2013.08.06 21:07:43 2: HMLAN_Parse: HMLAN1 new condition ok
2013.08.06 21:08:21 2: CUL_HM set sw_Subwoofer statusRequest
2013.08.06 21:17:31 2: CUL_HM set sw_Herd off

Ratlosigkeit macht sich breit.

AK-868 · 06 August 2013, 22:41:48

Jetzt hat wieder ein Kill nicht gereicht. kill -9 Prozessnummer und ./startfhem hat nur geholfen.

Log:
2013.08.06 21:50:09 1: 192.168.0.2:1000 disconnected, waiting to reappear
2013.08.06 21:50:09 1: 192.168.0.2:1000 reappeared (HMLAN1)
2013.08.06 21:50:21 2: CUL_HM set sw_FlurEG on-for-timer 17
2013.08.06 21:50:22 2: CUL_HM set sw_TreppenhausOG off
2013.08.06 21:50:22 3: Bewegungsmelder im Flur eingeschaltenNein
2013.08.06 21:50:22 2: HMLAN_Parse: HMLAN1 new condition ok
2013.08.06 21:50:32 2: CUL_HM set sw_TreppenhausOG on-for-timer 17
2013.08.06 21:50:32 2: CUL_HM set sw_FlurEG off
2013.08.06 21:50:32 3: Bewegungsmelder im TreppenhausOG eingeschaltenNein
2013.08.06 21:51:10 2: CUL_HM set sw_PC on
2013.08.06 21:51:23 2: CUL_HM set sw_TreppenhausOG on
2013.08.06 21:55:34 2: CUL_HM set sw_TreppenhausOG off

Danach kommt der Bootvorgang....

felix · 07 August 2013, 23:34:28

Das ist interessant. Ich wollte mich hier auch schon mit einem sehr ähnlichen oder vielleicht gleichen Problem melden, dass seit ca. 2 Wochen Auftritt.

Bei mir kommt's auch immer wieder (ca 1-3 mal pro Tag) vor, dass die power LED des HM-LAN blinkt (laut Anleitung heißt das keine Verbindung zur Software) und nichts mehr funktioniert. Nach ca. 20 Minuten kommt dann ein disconnect und sofort reconnect und alles läuft wieder. In der Zwischenzeit ist alles tot. Nur die Status LED am HM-LAN selber blinkt, das er die Autoren etc. Empfängt. Fhem scheint in dieser Zeit auch nichts zu machen und die Logs sind für den Zeitraum ohne Einträge.

Ich bin momentan unterwegs, schicke aber gerne mal meine Logs hier mit, sobald ich zu Hause bin.

Habe als Lösung schon mein fhem von der fritzbox auf einen raspberry verlagert, aber gleiches Problem. Das System lief so allerdings die letzten Wochen. Ich habe keine bewusste Änderung gemacht. Bin da etwas ratlos und versuche noch rauszufinden, ob es da eine regelmässigkeit gibt.

Grüße

Felix

AK-868 · 08 August 2013, 23:01:21

Ich hab gestern ein Update gemacht.

Bisher hat sich nichts mehr aufgehangen.

Bloed das ich nicht rausbekommen habe, warum das so oft war.

gruesse Andre

felix · 14 August 2013, 16:37:59

Bei mir besteht das Problem leider auch nach einem Update noch. Anbei habe ich mal ein Auzug aus dem Logfile angehängt mit einem Hänger zwischen 15:00 Uhr und 15:15. Es ist immer das gleiche Prinzip. Power-LED am HM-LAN blinkt, FHEM reagiert nicht und es dauert einige Minuten, bis ein disconnect und connect erfolgt. Dann weden einige der in der "hängenden" Zeit getätigten Schalt-Befehle abgearbeitet und alles geht wieder. Ich hab keine Ahnung, was das ist. Wenn irgend jemand eine Idde hat, wo ich mal schauen könnte, würde ich mich sehr freuen. So ist das manchmal schon etwas nervig ;)

Grüße Felix

Auszug aus HM-LAN Logfile:

Code Auswählen

2013-08-13_20:05:01 HML cond: ok
2013-08-13_20:05:01 HML Xmit-Events: ok:7 
2013-08-13_20:14:50 HML DISCONNECTED
2013-08-13_20:14:50 HML CONNECTED
2013-08-13_20:14:53 HML cond: ok
2013-08-13_20:14:53 HML Xmit-Events: ok:8 
2013-08-14_01:23:27 HML DISCONNECTED
2013-08-14_01:23:27 HML CONNECTED
2013-08-14_02:06:56 HML DISCONNECTED
2013-08-14_02:06:56 HML CONNECTED
2013-08-14_03:07:32 HML DISCONNECTED
2013-08-14_03:07:32 HML CONNECTED
2013-08-14_04:08:32 HML DISCONNECTED
2013-08-14_04:08:32 HML CONNECTED
2013-08-14_05:08:58 HML DISCONNECTED
2013-08-14_05:08:58 HML CONNECTED
2013-08-14_06:09:28 HML DISCONNECTED
2013-08-14_06:09:28 HML CONNECTED
2013-08-14_06:09:31 HML cond: ok
2013-08-14_06:09:32 HML Xmit-Events: ok:9 
2013-08-14_08:10:59 HML DISCONNECTED
2013-08-14_08:10:59 HML CONNECTED
2013-08-14_09:11:37 HML DISCONNECTED
2013-08-14_09:11:37 HML CONNECTED
2013-08-14_09:11:41 HML cond: ok
2013-08-14_09:11:41 HML Xmit-Events: ok:10 
2013-08-14_10:12:07 HML DISCONNECTED
2013-08-14_10:12:07 HML CONNECTED
2013-08-14_11:13:17 HML DISCONNECTED
2013-08-14_11:13:18 HML CONNECTED
2013-08-14_12:13:45 HML DISCONNECTED
2013-08-14_12:13:45 HML CONNECTED
2013-08-14_13:13:56 HML DISCONNECTED
2013-08-14_13:13:56 HML CONNECTED
2013-08-14_14:14:40 HML DISCONNECTED
2013-08-14_14:14:40 HML CONNECTED
2013-08-14_15:15:48 HML DISCONNECTED
2013-08-14_15:15:48 HML CONNECTED
2013-08-14_16:04:35 HML DISCONNECTED
2013-08-14_16:04:35 HML CONNECTED
2013-08-14_16:04:37 HML cond: ok
2013-08-14_16:04:38 HML Xmit-Events: ok:11

Auszug aus FHEM Logfile

Code Auswählen

2013.08.14 14:57:12.197 1: HMLAN_Send:  HML I:K
2013.08.14 14:57:12.221 1: HMLAN_Parse: HML V:03C1 sNo:JEQ0315329 d:1C6723 O:D56A93 t:236F9E12 IDcnt:0000
2013.08.14 14:57:14.120 1: HMLAN_Parse: HML R:E1F096E   stat:0000 t:236FA577 d:FF r:FFB8     m:12 8670 1F096E 000000 00E349
2013.08.14 14:57:37.222 1: HMLAN_Send:  HML I:K
2013.08.14 14:57:37.228 1: HMLAN_Parse: HML V:03C1 sNo:JEQ0315329 d:1C6723 O:D56A93 t:236FFFC5 IDcnt:0000
2013.08.14 14:57:46.778 1: HMLAN_Parse: HML R:E1F4CEE   stat:0000 t:2370250D d:FF r:FFB7     m:28 8670 1F4CEE 000000 00E348
2013.08.14 14:58:02.227 1: HMLAN_Send:  HML I:K
2013.08.14 14:58:02.233 1: HMLAN_Parse: HML V:03C1 sNo:JEQ0315329 d:1C6723 O:D56A93 t:23706176 IDcnt:0000
2013.08.14 14:58:07.929 1: HMLAN_Parse: HML R:E1D4015   stat:0000 t:237077AF d:FF r:FFBD     m:17 8670 1D4015 000000 00EA43
2013.08.14 14:58:27.236 1: HMLAN_Send:  HML I:K
2013.08.14 14:58:27.242 1: HMLAN_Parse: HML V:03C1 sNo:JEQ0315329 d:1C6723 O:D56A93 t:2370C32A IDcnt:0000
2013.08.14 14:58:45.816 1: HMLAN_Parse: HML R:E1CC931   stat:0000 t:23710BB4 d:FF r:FFB1     m:D2 8670 1CC931 000000 00A651
2013.08.14 14:58:52.242 1: HMLAN_Send:  HML I:K
2013.08.14 14:58:52.247 1: HMLAN_Parse: HML V:03C1 sNo:JEQ0315329 d:1C6723 O:D56A93 t:237124DB IDcnt:0000
2013.08.14 14:59:09.669 1: HMLAN_Parse: HML R:E197DB2   stat:0000 t:237168E4 d:FF r:FFB8     m:9B 8670 197DB2 000000 00E84B
2013.08.14 14:59:17.249 1: HMLAN_Send:  HML I:K
2013.08.14 14:59:17.254 1: HMLAN_Parse: HML V:03C1 sNo:JEQ0315329 d:1C6723 O:D56A93 t:2371868E IDcnt:0000
2013.08.14 14:59:42.253 1: HMLAN_Send:  HML I:K
2013.08.14 14:59:42.259 1: HMLAN_Parse: HML V:03C1 sNo:JEQ0315329 d:1C6723 O:D56A93 t:2371E83E IDcnt:0000
2013.08.14 14:59:44.372 1: HMLAN_Parse: HML R:E1F096E   stat:0000 t:2371F078 d:FF r:FFB8     m:13 8670 1F096E 000000 00E349
2013.08.14 15:00:03.030 1: HMLAN_Parse: HML R:E1F4CEE   stat:0000 t:2372395D d:FF r:FFB6     m:29 8670 1F4CEE 000000 00E348
2013.08.14 15:00:07.262 1: HMLAN_Send:  HML I:K
2013.08.14 15:00:07.267 1: HMLAN_Parse: HML V:03C1 sNo:JEQ0315329 d:1C6723 O:D56A93 t:237249F2 IDcnt:0000
2013.08.14 15:00:32.270 1: HMLAN_Send:  HML I:K
2013.08.14 15:00:32.276 1: HMLAN_Parse: HML V:03C1 sNo:JEQ0315329 d:1C6723 O:D56A93 t:2372ABA6 IDcnt:0000
2013.08.14 15:00:39.947 1: HMLAN_Parse: HML R:E1D4015   stat:0000 t:2372C996 d:FF r:FFBD     m:18 8670 1D4015 000000 00EA43
2013.08.14 15:15:46.792 1: HMLAN_Parse: HML R:E1CC931   stat:0000 t:237322F5 d:FF r:FFB1     m:D3 8670 1CC931 000000 00A651
2013.08.14 15:15:47.535 1: HMLAN_Send:  HML I:K
2013.08.14 15:15:48.315 1: 192.168.1.22:1000 disconnected, waiting to reappear
2013.08.14 15:15:48.355 1: 192.168.1.22:1000 reappeared (HML)
2013.08.14 15:15:48.357 1: HMLAN_Send:  HML I:AD56A93
2013.08.14 15:15:48.359 1: HMLAN_Send:  HML I:C
2013.08.14 15:15:48.360 1: HMLAN_Send:  HML I:Y01,01,
2013.08.14 15:15:48.361 1: HMLAN_Send:  HML I:Y02,00,
2013.08.14 15:15:48.362 1: HMLAN_Send:  HML I:Y03,00,
2013.08.14 15:15:48.363 1: HMLAN_Send:  HML I:Y03,00,
2013.08.14 15:15:48.363 1: HMLAN_Send:  HML I:T199E3F84,04,00,00000000
2013.08.14 15:15:48.401 1: HMLAN_Parse: HML V:03C1 sNo:JEQ0315329 d:1C6723 O:D56A93 t:2380A69E IDcnt:0000
2013.08.14 15:15:48.403 1: HMLAN_Parse: HML R:E1F096E   stat:0000 t:237402D3 d:FF r:FFB8     m:14 8670 1F096E 000000 00E349
2013.08.14 15:15:48.448 1: HMLAN_Parse: HML R:E197DB2   stat:0000 t:23740AE0 d:FF r:FFB8     m:9C 8670 197DB2 000000 00E94B
2013.08.14 15:15:48.525 1: HMLAN_Parse: HML R:E1F4CEE   stat:0000 t:23741600 d:FF r:FFB7     m:2A 8670 1F4CEE 000000 00E348
2013.08.14 15:15:48.571 1: HMLAN_Parse: HML R:E1D4015   stat:0000 t:2374E2D5 d:FF r:FFBD     m:19 8670 1D4015 000000 00EA43
2013.08.14 15:15:48.615 1: HMLAN_Parse: HML R:E1CC931   stat:0000 t:2375018F d:FF r:FFB1     m:D4 8670 1CC931 000000 00A551
2013.08.14 15:15:48.660 1: HMLAN_Parse: HML R:E1F096E   stat:0000 t:2375DD81 d:FF r:FFB8     m:15 8670 1F096E 000000 00E349
2013.08.14 15:15:48.705 1: HMLAN_Parse: HML R:E197DB2   stat:0000 t:23767435 d:FF r:FFB7     m:9D 8670 197DB2 000000 00E94B
2013.08.14 15:15:48.781 1: HMLAN_Parse: HML R:E1F4CEE   stat:0000 t:2376B408 d:FF r:FFB7     m:2B 8670 1F4CEE 000000 00E348
2013.08.14 15:15:48.827 1: HMLAN_Parse: HML R:E1D4015   stat:0000 t:2376C36D d:FF r:FFBD     m:1A 8670 1D4015 000000 00E943
2013.08.14 15:15:48.872 1: HMLAN_Parse: HML R:E1CC931   stat:0000 t:2377A18D d:FF r:FFB1     m:D5 8670 1CC931 000000 00A551
2013.08.14 15:15:48.917 1: HMLAN_Parse: HML R:E1F096E   stat:0000 t:23787994 d:FF r:FFB8     m:16 8670 1F096E 000000 00E349
2013.08.14 15:15:48.962 1: HMLAN_Parse: HML R:E197DB2   stat:0000 t:2378A5DE d:FF r:FFB7     m:9E 8670 197DB2 000000 00E94B
2013.08.14 15:15:49.040 1: HMLAN_Parse: HML R:E1F4CEE   stat:0000 t:2379196A d:FF r:FFB7     m:2C 8670 1F4CEE 000000 00E348
2013.08.14 15:15:49.085 1: HMLAN_Parse: HML R:E1D4015   stat:0000 t:23796668 d:FF r:FFBD     m:1B 8670 1D4015 000000 00EA43
2013.08.14 15:15:49.130 1: HMLAN_Parse: HML R:E1CC931   stat:0000 t:237A09E1 d:FF r:FFB1     m:D6 8670 1CC931 000000 00A451
2013.08.14 15:15:49.175 1: HMLAN_Parse: HML R:E197DB2   stat:0000 t:237A9EDE d:FF r:FFB8     m:9F 8670 197DB2 000000 00E94B
2013.08.14 15:15:49.252 1: HMLAN_Parse: HML R:E1F096E   stat:0000 t:237ADD00 d:FF r:FFB8     m:17 8670 1F096E 000000 00E349
2013.08.14 15:15:49.298 1: HMLAN_Parse: HML R:E1F4CEE   stat:0000 t:237B471F d:FF r:FFB6     m:2D 8670 1F4CEE 000000 00E348
2013.08.14 15:15:49.344 1: HMLAN_Parse: HML R:E1D4015   stat:0000 t:237BD0BA d:FF r:FFBD     m:1C 8670 1D4015 000000 00E943
2013.08.14 15:15:49.390 1: HMLAN_Parse: HML R:E1CC931   stat:0000 t:237C398C d:FF r:FFB1     m:D7 8670 1CC931 000000 00A551
2013.08.14 15:15:49.435 1: HMLAN_Parse: HML R:E1F096E   stat:0000 t:237D08C0 d:FF r:FFB8     m:18 8670 1F096E 000000 00E349
2013.08.14 15:15:49.481 1: HMLAN_Parse: HML R:E1F4CEE   stat:0000 t:237D3C2E d:FF r:FFB7     m:2E 8670 1F4CEE 000000 00E348
2013.08.14 15:15:49.526 1: HMLAN_Parse: HML R:E197DB2   stat:0000 t:237D5946 d:FF r:FFB8     m:A0 8670 197DB2 000000 00E94B
2013.08.14 15:15:49.603 1: HMLAN_Parse: HML R:E1D4015   stat:0000 t:237E0266 d:FF r:FFBD     m:1D 8670 1D4015 000000 00EA43
2013.08.14 15:15:49.648 1: HMLAN_Parse: HML R:E1CC931   stat:0000 t:237E3092 d:FF r:FFB1     m:D8 8670 1CC931 000000 00A551
2013.08.14 15:15:49.693 1: HMLAN_Parse: HML R:E1F096E   stat:0000 t:237EFBDB d:FF r:FFB8     m:19 8670 1F096E 000000 00E349
2013.08.14 15:15:49.739 1: HMLAN_Parse: HML R:E197DB2   stat:0000 t:237FDB08 d:FF r:FFB8     m:A1 8670 197DB2 000000 00E84B
2013.08.14 15:15:49.816 1: HMLAN_Parse: HML R:E1F4CEE   stat:0000 t:237FF2A1 d:FF r:FFB7     m:2F 8670 1F4CEE 000000 00E348
2013.08.14 15:15:49.861 1: HMLAN_Parse: HML R:E1D4015   stat:0000 t:237FFC63 d:FF r:FFBD     m:1E 8670 1D4015 000000 00EA43
2013.08.14 15:16:05.606 1: HMLAN_Parse: HML R:E1CC931   stat:0000 t:2380E9F6 d:FF r:FFB1     m:D9 8670 1CC931 000000 00A551
2013.08.14 15:16:13.371 1: HMLAN_Send:  HML I:K
2013.08.14 15:16:13.378 1: HMLAN_Parse: HML V:03C1 sNo:JEQ0315329 d:1C6723 O:D56A93 t:2381085A IDcnt:0000
2013.08.14 15:16:38.380 1: HMLAN_Send:  HML I:K
2013.08.14 15:16:38.385 1: HMLAN_Parse: HML V:03C1 sNo:JEQ0315329 d:1C6723 O:D56A93 t:23816A0D IDcnt:0000
2013.08.14 15:16:56.385 1: HMLAN_Parse: HML R:E1F096E   stat:0000 t:2381B058 d:FF r:FFB8     m:1A 8670 1F096E 000000 00E349
2013.08.14 15:17:03.386 1: HMLAN_Send:  HML I:K
2013.08.14 15:17:03.392 1: HMLAN_Parse: HML V:03C1 sNo:JEQ0315329 d:1C6723 O:D56A93 t:2381CBBF IDcnt:0000
2013.08.14 15:17:26.271 1: HMLAN_Parse: HML R:E197DB2   stat:0000 t:2382251B d:FF r:FFB8     m:A2 8670 197DB2 000000 00E94B
2013.08.14 15:17:28.392 1: HMLAN_Send:  HML I:K
2013.08.14 15:17:28.398 1: HMLAN_Parse: HML V:03C1 sNo:JEQ0315329 d:1C6723 O:D56A93 t:23822D71 IDcnt:0000
2013.08.14 15:17:45.551 1: HMLAN_Parse: HML R:E1F4CEE   stat:0000 t:2382706D d:FF r:FFB7     m:30 8670 1F4CEE 000000 00E348
2013.08.14 15:17:53.397 1: HMLAN_Send:  HML I:K
2013.08.14 15:17:53.403 1: HMLAN_Parse: HML V:03C1 sNo:JEQ0315329 d:1C6723 O:D56A93 t:23828F22 IDcnt:0000
2013.08.14 15:18:03.815 1: HMLAN_Parse: HML R:E1D4015   stat:0000 t:2382B7C8 d:FF r:FFBD     m:1F 8670 1D4015 000000 00EA43
2013.08.14 15:18:18.406 1: HMLAN_Send:  HML I:K
2013.08.14 15:18:18.412 1: HMLAN_Parse: HML V:03C1 sNo:JEQ0315329 d:1C6723 O:D56A93 t:2382F0D6 IDcnt:0000
2013.08.14 15:18:43.415 1: HMLAN_Send:  HML I:K
2013.08.14 15:18:43.420 1: HMLAN_Parse: HML V:03C1 sNo:JEQ0315329 d:1C6723 O:D56A93 t:2383528A IDcnt:0000
2013.08.14 15:18:49.613 1: HMLAN_Parse: HML R:E1CC931   stat:0000 t:23836AB4 d:FF r:FFB1     m:DA 8670 1CC931 000000 00A651
2013.08.14 15:19:08.423 1: HMLAN_Send:  HML I:K
2013.08.14 15:19:08.429 1: HMLAN_Parse: HML V:03C1 sNo:JEQ0315329 d:1C6723 O:D56A93 t:2383B43E IDcnt:0000
2013.08.14 15:19:33.428 1: HMLAN_Send:  HML I:K

AK-868 · 15 August 2013, 09:58:25

Hast du evtl. SCI-3-FM 3? Ich hab jetzt mehrfach feststellen können das die den HM-Lan so zubomben. Das sich fhem aufhängt.

Der HMLan kann auch schuld daran sein. Was du mal umstellen könntest, die Geschwindigkeit an dem LAN-Port wo HMLAN dranhängt. Ich hab den jetzt auf Port2 stecken mit 100mbit ecomode.

Bisher läuft es jetzt wieder stabil.

Das kommt beim Overload. Sowas scheint in deinen Logs jetzt nicht zu sein:

2: HMLAN_Parse: HMLAN1 new condition Overload-released
2: HMLAN_Parse: HMLAN1 new condition Overload-released
2: HMLAN_Parse: HMLAN1 new condition ERROR-Overload

felix · 15 August 2013, 11:16:24

Ja, von dem HM-SCI-3-FM habe ich momentan 4 Stück in Betrieb. Einen Overload habe ich aber noch nicht gesehen. (Im August keiner, habe gerade nachgeschaut).

Den Port werde ich heute Abend mal umstellen.

Werde mal mein Profil/Signatur bearbeiten mit mehr Einzelheiten.