HMLAN Adapter wechselt permanent zwischen disconnected / connected

Michi240281 · 02 März 2014, 14:56:32

Hier mal mit "Apptime maxDly":

                    name             function    max  count    total  average maxDly
              tmr-Twilight_fireEvent      HASH(0x21115e8)      4      1        4     4.00 33398019 HASH(0x21115e8)
              tmr-Twilight_fireEvent      HASH(0x2362bd8)      3      1        3     3.00 31092782 HASH(0x2362bd8)
              tmr-Twilight_fireEvent      HASH(0x222d090)      4      1        4     4.00 28803640 HASH(0x222d090)
              tmr-Twilight_fireEvent       HASH(0xf5a4e0)      4      1        4     4.00 26491361 HASH(0xf5a4e0)
              tmr-Twilight_fireEvent      HASH(0x1ec6a30)      4      1        4     4.00 26100862 HASH(0x1ec6a30)
              tmr-Twilight_fireEvent      HASH(0x1c9da50)      4      1        4     4.00 24516131 HASH(0x1c9da50)
               tmr-HttpUtils_ConnErr      HASH(0x19c35e8)      0      1        0     0.00  28138 
               tmr-HttpUtils_ReadErr      HASH(0x19c35e8)      0      1        0     0.00  28133 
               tmr-HttpUtils_ConnErr      HASH(0x2405c70)      0      1        0     0.00  28012 
               tmr-HttpUtils_ConnErr      HASH(0x192a450)      0      1        0     0.00  28003 
               tmr-HttpUtils_ConnErr      HASH(0x2143768)      0      1        0     0.00  27998 
               tmr-HttpUtils_ConnErr      HASH(0x14cb6a8)      0      1        0     0.00  27993 
               tmr-HttpUtils_ConnErr      HASH(0x23bd2a8)      0      1        0     0.00  27988 
               tmr-HttpUtils_ConnErr      HASH(0x2425168)      0      1        0     0.00  27983 
               tmr-HttpUtils_ConnErr      HASH(0x199aff0)      0      1        0     0.00  27977 
               tmr-HttpUtils_ReadErr      HASH(0x192a450)      0      1        0     0.00  27948 
               tmr-HttpUtils_ReadErr      HASH(0x14cb6a8)      0      1        0     0.00  27947 
               tmr-HttpUtils_ReadErr      HASH(0x2425168)      0      1        0     0.00  27947 
               tmr-HttpUtils_ReadErr      HASH(0x2405c70)      0      1        0     0.00  27945 
               tmr-HttpUtils_ReadErr      HASH(0x199aff0)      0      1        0     0.00  27944 
               tmr-HttpUtils_ReadErr      HASH(0x23bd2a8)      0      1        0     0.00  27944

@Frank: Werde das Modul gleich mal installieren.

frank · 02 März 2014, 16:08:05

das sieht wohl ziehmlich eindeutig aus.

da werden viele http zugriffe gemacht mit fiesen maxDly werten. wahrscheinlich nicht zu erreichen. oder alles überschneidet sich. mit dem anderen modul kannst du dann ganz genau erkennen, welches modul zu welcher zeit mit welcher resultierenden verzögerung einen aufruf startet. dein twilight wohl auch.

gruss frank

Michi240281 · 02 März 2014, 16:28:19

Also ich habe jetzt mal das PerfMon Modul installiert und so wie es aussieht, ist das ENIGMA Modul schuld.

Das Modul scheint minütlich die komplette Sender- und Timerliste und einige weitere Readings vom Receiver abzufragen. Das dauert dann recht lange. Verstehe ich nicht, warum das sein muss. Senderliste würde doch reichen, die einmal am Tag auszulesen. Wenn es da kein Update gibt, bleibt wohl nix anderers übrig, als das Modul wieder rauzuschmeißen.

Wieso macht das Twilight denn solche Sachen? Hier alles aus der cfg, was das twilight Modul betrifft:

Code Auswählen

define Twilight Twilight 50.9833 6.0 1 651465
attr Twilight group Umwelt
attr Twilight room Haus
attr Twilight stateFormat light

In folgendem Logauszug passt das aber irgendwie nicht zusammen! Da soll ein Freeze von etwas ausgelöst worden sein, das um 16:36:58 stattgefunden hat. Da war aber garnix?!?!?

Code Auswählen

2014.03.02 16:36:54.492 4: HTTP FHEMWEB:192.168.188.177:58912 GET /fhem/pgm2/style.css
2014.03.02 16:36:54.499 4: HTTP FHEMWEB:192.168.188.177:58911 GET /fhem/pgm2/dashboard.js
2014.03.02 16:36:54.506 4: HTTP FHEMWEB:192.168.188.177:58910 GET /fhem/pgm2/jquery.min.js
2014.03.02 16:36:54.512 4: HTTP FHEMWEB:192.168.188.177:58913 GET /fhem/pgm2/jquery-ui.min.js
2014.03.02 16:36:54.518 4: HTTP FHEMWEB:192.168.188.177:58907 GET /fhem/pgm2/fhemweb_colorpicker.js
2014.03.02 16:36:54.523 4: HTTP FHEMWEB:192.168.188.177:58912 GET /fhem/pgm2/fhemweb.js
2014.03.02 16:36:54.530 4: Connection accepted from FHEMWEB:192.168.188.177:58914
2014.03.02 16:36:54.532 4: HTTP FHEMWEB:192.168.188.177:58911 GET /fhem/pgm2/fhemweb_multiple.js
2014.03.02 16:36:54.538 4: HTTP FHEMWEB:192.168.188.177:58910 GET /fhem/pgm2/fhemweb_noArg.js
2014.03.02 16:36:54.545 4: HTTP FHEMWEB:192.168.188.177:58907 GET /fhem/pgm2/fhemweb_svg.js
2014.03.02 16:36:54.550 4: HTTP FHEMWEB:192.168.188.177:58912 GET /fhem/pgm2/fhemweb_textField.js
2014.03.02 16:36:54.555 4: HTTP FHEMWEB:192.168.188.177:58911 GET /fhem/pgm2/fhemweb_time.js
2014.03.02 16:36:54.561 4: HTTP FHEMWEB:192.168.188.177:58910 GET /fhem/pgm2/dashboard_darkstyle.css
2014.03.02 16:36:54.567 4: HTTP FHEMWEB:192.168.188.177:58914 GET /fhem/pgm2/svg.js
2014.03.02 16:36:54.572 4: HTTP FHEMWEB:192.168.188.177:58913 GET /fhem/pgm2/fhemweb_slider.js
2014.03.02 16:36:54.578 4: HTTP FHEMWEB:192.168.188.177:58907 GET /fhem/icons/favicon
2014.03.02 16:36:54.653 4: HTTP FHEMWEB:192.168.188.177:58907 GET /fhem/images/default/icoHaus.png
2014.03.02 16:36:54.660 4: HTTP FHEMWEB:192.168.188.177:58912 GET /fhem/images/default/icoEverything.png
2014.03.02 16:36:54.665 4: HTTP FHEMWEB:192.168.188.177:58911 GET /fhem/images/default/fhemicon_dark.png
2014.03.02 16:36:54.770 4: HTTP FHEMWEB:192.168.188.177:58907 GET /fhem?XHR=1&inform=type=status;filter=room=Logs×tamp=1393774643083
2014.03.02 16:36:57.608 4: Connection closed for FHEMWEB:192.168.188.177:58907
2014.03.02 16:36:57.612 4: HTTP FHEMWEB:192.168.188.177:58912 GET /fhem/FileLog_logWrapper&dev=Logfile&type=text&file=fhem-2014-03.log
2014.03.02 16:37:04.109 1: Perfmon: possible freeze starting at 16:36:58, delay is 6.107

frank · 02 März 2014, 16:46:27

ZitatWieso macht das Twilight denn solche Sachen? Hier alles aus der cfg, was das twilight Modul betrifft:

Code Auswählen Erweitern
define Twilight Twilight 50.9833 6.0 1 651465

vielleicht die namensgleichheit!

ansonsten bei yahoo mal schauen ob die wetterseite (651465) noch stimmt.

gruss frank

Michi240281 · 02 März 2014, 20:14:17

Habs mal in "My_Twilight" geändert.

Die Wetter-ID stimmt noch.

martinp876 · 03 März 2014, 08:28:53

perform misst eine verzoegerung eines 1-sec timers - wenn der delay groesser 1 sec ist wird es geloggt.
Apptime macht keinen log bei entsprechenden events, zeigt aber alle delays zu real aktiven timern.
Apptime hat delays von ueber 30 sec in mehrere Faellen festgestellt, aber keine einzelne Prozedur, die eine entsprechende Laufzeit hat. Der FHEM-kernal sollte einen solchen delays erzeugen. Damit tippe ich auf eine FHEM-externe Application, was auch durch den letzten Log untermauert wird.
Wie ist den die Auslastung deiner CPU?

wtue · 06 März 2014, 21:02:02

Hallo zusammen,
hier mal meine Beobachtungen zum Thema.

Ich betreibe FHEM an einer FB7390 mit dem Image aus dem Fhem Projekt. Habe inzwischen hauptsächlich Rolladenaktoren in Betrieb. Nach ersten Versuchen und fortschreitendem Montagestand habe ich vom CUL auf HMLAN umgestellt, weil einige Aktoren schlecht, bzw. gar nicht erreichbar waren. Mit dem HMLAN hat sich die Funksituation verbessert (bessere RSSI-Werte) .

Allerdings sind mir deutliche Verzögerungen bei den Reaktionen der Aktoren auf die Befehle aus dem Webgui aufgefallen. Im Log hatte ich ebenfalls diese hier beschriebennen Aussetzer.

Code Auswählen


2014.03.05 17:00:46.664 2: CUL_HM set EG_Roll_Kueche2 statusRequest
2014.03.05 17:01:21.205 1: HMLAN_Parse: HMLAN1 new condition timeout
2014.03.05 17:01:21.213 1: 172.16.2.43:1000 disconnected, waiting to reappear
2014.03.05 17:01:21.216 1: HMLAN_Parse: HMLAN1 new condition disconnected
2014.03.05 17:02:32.909 1: 172.16.2.43:1000 reappeared (HMLAN1)
2014.03.05 17:02:32.918 1: HMLAN_Parse: HMLAN1 new condition init
2014.03.05 17:02:32.979 1: HMLAN_Parse: HMLAN1 new condition ok
2014.03.05 17:02:41.828 2: CUL_HM set EG_Roll_EZ1 statusRequest
2014.03.05 17:02:46.823 2: CUL_HM set EG_Roll_Kueche1 statusRequest
2014.03.05 17:02:47.860 2: CUL_HM set EG_Roll_Kueche2 statusRequest
2014.03.05 17:04:43.027 2: CUL_HM set EG_Roll_EZ1 statusRequest
2014.03.05 17:04:48.019 2: CUL_HM set EG_Roll_Kueche1 statusRequest
2014.03.05 17:04:49.056 2: CUL_HM set EG_Roll_Kueche2 statusRequest
2014.03.05 17:05:31.993 1: HMLAN_Parse: HMLAN1 new condition timeout
2014.03.05 17:05:32.000 1: 172.16.2.43:1000 disconnected, waiting to reappear
2014.03.05 17:05:32.004 1: HMLAN_Parse: HMLAN1 new condition disconnected
2014.03.05 17:05:37.029 1: 172.16.2.43:1000 reappeared (HMLAN1)
2014.03.05 17:05:37.037 1: HMLAN_Parse: HMLAN1 new condition init
2014.03.05 17:05:37.074 1: HMLAN_Parse: HMLAN1 new condition ok
2014.03.05 17:06:44.236 2: CUL_HM set EG_Roll_EZ1 statusRequest
2014.03.05 17:06:49.218 2: CUL_HM set EG_Roll_Kueche1 statusRequest
2014.03.05 17:06:50.256 2: CUL_HM set EG_Roll_Kueche2 statusRequest
2014.03.05 17:08:45.432 2: CUL_HM set EG_Roll_EZ1 statusRequest

Mit den hier beschriebenen Methoden konnte 99_perfmon.pm und apptime konnte ich nicht wirklich einen "Schuldigen" ausmachen. Habe dieses Problem aber erstmal zurückgestellt weil ich noch einen Rollenaktor hatte, den ich per FHEM nicht ansprechen konnte. Der Aktor war mal richtig angelernt und hat auch auf FHEM Befehle reagiert. Aber, warum auch immer er tat's nicht mehr. Ich ging schon von einem Defekt aus, habe aber sicherheitshalber noch mal die Anlerntaste gedrückt und angelernt mit set HMLAN1 hmPairSerial KEQXXXXXXX . Was soll ich sagen, der Aktor funktioniert und meine Unterbrechungen sind auch weg. Das Modul perfmon mäkelt zwar gelegengtlich, aber alles ist gut.

Code Auswählen


2014.03.06 12:30:55.472 0: Server shutdown
2014.03.06 12:30:59.252 1: Including fhem.cfg
2014.03.06 12:31:00.245 2: Perfmon: ready to watch out for delays greater than one second
2014.03.06 12:31:00.386 3: telnetPort: port 7072 opened
2014.03.06 12:31:01.431 3: WEB: port 8083 opened
2014.03.06 12:31:01.439 3: WEBphone: port 8084 opened
2014.03.06 12:31:01.450 3: WEBtablet: port 8085 opened
2014.03.06 12:31:02.149 2: eventTypes: loaded 1545 events from ./log/eventTypes.txt
2014.03.06 12:31:02.455 1: HMLAN_Parse: HMLAN1 new condition disconnected
2014.03.06 12:31:02.458 3: Opening HMLAN1 device 172.16.2.43:1000
2014.03.06 12:31:02.502 3: HMLAN1 device opened
2014.03.06 12:31:02.508 1: HMLAN_Parse: HMLAN1 new condition init
2014.03.06 12:31:02.596 3: Opening fritzbox device fritz.box:2002
2014.03.06 12:31:02.606 3: fritzbox device opened
2014.03.06 12:31:02.612 1: FBAHA fritzbox registered with handle: 0000000a
2014.03.06 12:31:07.178 1: Including ./log/fhem.save
2014.03.06 12:31:08.160 1: usb create starting
2014.03.06 12:31:08.890 1: usb create end
2014.03.06 12:31:08.894 2: Werner's Spielwiese
2014.03.06 12:31:08.896 0: Server started with 92 defined entities (version $Id: fhem.pl 5126 2014-03-04 16:27:09Z rudolfkoenig $, os linux, user boxusr99, pid 2737)
2014.03.06 12:31:08.899 1: Perfmon: possible freeze starting at 12:31:01, delay is 7.898
2014.03.06 12:31:08.914 1: HMLAN_Parse: HMLAN1 new condition ok
2014.03.06 12:31:11.536 3: Device OG_HZ_Bad added to ActionDetector with 000:10 time
2014.03.06 12:31:11.693 3: Device UG_HZ_ELW added to ActionDetector with 000:10 time
2014.03.06 12:31:12.845 2: CUL_HM set EG_Dimmer_WZ statusRequest
2014.03.06 12:31:13.866 2: CUL_HM set EG_Roll_EZ1 statusRequest
2014.03.06 12:31:14.883 2: CUL_HM set EG_Roll_EZ2 statusRequest
2014.03.06 12:31:15.901 2: CUL_HM set EG_Roll_Erker1 statusRequest
2014.03.06 12:31:16.919 2: CUL_HM set EG_Roll_Erker2 statusRequest
2014.03.06 12:31:17.937 2: CUL_HM set EG_Roll_Erker3 statusRequest
2014.03.06 12:31:18.955 2: CUL_HM set EG_Roll_Kueche1 statusRequest
2014.03.06 12:31:19.974 2: CUL_HM set EG_Roll_Kueche2 statusRequest
2014.03.06 12:31:20.991 2: CUL_HM set EG_Roll_WZ statusRequest
2014.03.06 12:31:22.006 2: CUL_HM set HM_Schaltsteckdose1 statusRequest
2014.03.06 12:31:23.023 2: CUL_HM set OG_Licht_Buero statusRequest
2014.03.06 12:31:24.040 2: CUL_HM set UG_Roll_Kueche statusRequest
2014.03.06 13:20:35.473 3: update get http://fhem.de/fhemupdate4/svn/controls_fhem.txt
2014.03.06 13:20:37.046 1: Perfmon: possible freeze starting at 13:20:36, delay is 1.045
2014.03.06 18:11:43.014 2: CUL_HM set HM_Schaltsteckdose1 on
2014.03.06 18:59:14.015 2: CUL_HM set EG_Roll_EZ1 off
2014.03.06 18:59:14.035 2: CUL_HM set EG_Roll_Erker1 off
2014.03.06 18:59:14.049 2: CUL_HM set EG_Roll_Erker2 off
2014.03.06 18:59:14.063 2: CUL_HM set EG_Roll_Erker3 off
2014.03.06 18:59:14.076 2: CUL_HM set EG_Roll_Kueche1 off
2014.03.06 18:59:14.089 2: CUL_HM set EG_Roll_Kueche2 off
2014.03.06 18:59:14.102 2: CUL_HM set EG_Roll_WZ off
2014.03.06 18:59:14.115 2: CUL_HM set UG_Roll_Kueche off

Hier habe ich mal ein update force angestossen, danach geht es aber normal weiter. Alles ist gut.

Code Auswählen


2014.03.06 19:52:25.775 1: update 1171 file(s) have been updated.
2014.03.06 19:52:25.840 1: update A new version of fhem.pl was installed, 'shutdown restart' is required!
2014.03.06 20:14:42.562 0: Server shutdown
2014.03.06 20:14:46.762 1: Including fhem.cfg
2014.03.06 20:14:47.804 2: Perfmon: ready to watch out for delays greater than one second
2014.03.06 20:14:47.954 3: telnetPort: port 7072 opened
2014.03.06 20:14:49.497 3: WEB: port 8083 opened
2014.03.06 20:14:49.505 3: WEBphone: port 8084 opened
2014.03.06 20:14:49.515 3: WEBtablet: port 8085 opened
2014.03.06 20:14:50.256 2: eventTypes: loaded 1545 events from ./log/eventTypes.txt
2014.03.06 20:14:50.575 1: HMLAN_Parse: HMLAN1 new condition disconnected
2014.03.06 20:14:50.579 3: Opening HMLAN1 device 172.16.2.43:1000
2014.03.06 20:14:50.625 3: HMLAN1 device opened
2014.03.06 20:14:50.632 1: HMLAN_Parse: HMLAN1 new condition init
2014.03.06 20:14:50.723 3: Opening fritzbox device fritz.box:2002
2014.03.06 20:14:50.763 3: fritzbox device opened
2014.03.06 20:14:50.785 1: FBAHA fritzbox registered with handle: 0000000b
2014.03.06 20:14:55.849 1: Including ./log/fhem.save
2014.03.06 20:14:56.864 1: usb create starting
2014.03.06 20:14:57.615 1: usb create end
2014.03.06 20:14:57.619 2: Werner's Spielwiese
2014.03.06 20:14:57.621 0: Server started with 92 defined entities (version $Id: fhem.pl 5126 2014-03-04 16:27:09Z rudolfkoenig $, os linux, user boxusr99, pid 2923)
2014.03.06 20:14:57.625 1: Perfmon: possible freeze starting at 20:14:48, delay is 9.623
2014.03.06 20:14:57.641 1: HMLAN_Parse: HMLAN1 new condition ok
2014.03.06 20:15:00.143 3: Device OG_HZ_Bad added to ActionDetector with 000:10 time
2014.03.06 20:15:00.299 3: Device UG_HZ_ELW added to ActionDetector with 000:10 time
2014.03.06 20:15:01.464 2: CUL_HM set EG_Dimmer_WZ statusRequest
2014.03.06 20:15:02.486 2: CUL_HM set EG_Roll_EZ1 statusRequest
2014.03.06 20:15:03.504 2: CUL_HM set EG_Roll_EZ2 statusRequest
2014.03.06 20:15:04.522 2: CUL_HM set EG_Roll_Erker1 statusRequest
2014.03.06 20:15:05.540 2: CUL_HM set EG_Roll_Erker2 statusRequest
2014.03.06 20:15:06.558 2: CUL_HM set EG_Roll_Erker3 statusRequest
2014.03.06 20:15:07.575 2: CUL_HM set EG_Roll_Kueche1 statusRequest
2014.03.06 20:15:08.593 2: CUL_HM set EG_Roll_Kueche2 statusRequest
2014.03.06 20:15:09.611 2: CUL_HM set EG_Roll_WZ statusRequest
2014.03.06 20:15:10.629 2: CUL_HM set HM_Schaltsteckdose1 statusRequest
2014.03.06 20:15:11.647 2: CUL_HM set OG_Licht_Buero statusRequest
2014.03.06 20:15:12.665 2: CUL_HM set UG_Roll_Kueche statusRequest
2014.03.06 20:19:11.309 1: Perfmon: possible freeze starting at 20:19:10, delay is 1.308
2014.03.06 20:41:28.348 1: Perfmon: possible freeze starting at 20:41:26, delay is 2.347

Vielleicht hilft es ja jemandem weiter.

Gruß Werner

el_migu_el · 07 März 2014, 16:15:00

Hallo,
ich bin neu im Thema fhem und Heimautomatisierung generell.
Leider habe ich das Problem mit den Dis/connects auch.
Als blutiger Anfänger bin noch nicht über ein Setup mit fhem und HMLAN hinaus gekommen

Sprich meine fhem.cfg ist entsprechend minimal.

Code Auswählen

#attr global logfile ./log/fhem-%Y-%m.log
attr global logfile -
attr global modpath .
attr global motd none
attr global statefile ./log/fhem.save
attr global verbose 5
attr global updateInBackground 1

define telnetPort telnet 7072 global

#define HM HMinfo
# set HM help

define HMLAN1 HMLAN 192.168.0.6:1000
attr HMLAN1 hmId 2576E2

define WEB FHEMWEB 8083 global

define WEBphone FHEMWEB 8084 global
# attr WEBphone stylesheetPrefix smallscreen
attr WEBphone stylesheetPrefix ios7

define WEBtablet FHEMWEB 8085 global
attr WEBtablet stylesheetPrefix ios7

# Fake FileLog entry, to access the fhem log from FHEMWEB 
define Logfile FileLog ./log/fhem-%Y-%m.log fakelog

define autocreate autocreate
attr autocreate filelog ./log/%NAME-%Y.log

define eventTypes eventTypes ./log/eventTypes.txt

Das HMLAN hängt am gleichen Switch wie das QNAP NAS. Der Switch verbindet via Powerline zum Kabelmodem/Router. Im Netz gibts noch ein Canon Drucker, zwei Macbook's, iPhones und iPads als auch ein AppleTV.

Was mich jedoch noch erstaunt hat ist, dass das HMLAN nur eine Verbindung vom fhem zulässt wenn AES aktiviert ist?

ping zum HMLAN ist denke ich ok:

Code Auswählen

[~] # ping 192.168.0.6
PING 192.168.0.6 (192.168.0.6): 56 data bytes
64 bytes from 192.168.0.6: icmp_seq=0 ttl=128 time=1.9 ms
64 bytes from 192.168.0.6: icmp_seq=1 ttl=128 time=0.3 ms
64 bytes from 192.168.0.6: icmp_seq=2 ttl=128 time=0.3 ms
64 bytes from 192.168.0.6: icmp_seq=3 ttl=128 time=0.4 ms
64 bytes from 192.168.0.6: icmp_seq=4 ttl=128 time=0.3 ms
64 bytes from 192.168.0.6: icmp_seq=5 ttl=128 time=0.4 ms
64 bytes from 192.168.0.6: icmp_seq=6 ttl=128 time=0.4 ms
64 bytes from 192.168.0.6: icmp_seq=7 ttl=128 time=0.3 ms

Die Disconnect/Connect Sequenzen laufen immer gleich ab, wodurch ich hier nur ein Ausschnit aus dem Log poste.

Code Auswählen

014.03.07 13:29:32 1: Including fhem-hmlan.cfg
2014.03.07 13:29:32 5: Cmd: >attr global logfile -<
2014.03.07 13:29:32 5: Cmd: >attr global modpath .<
2014.03.07 13:29:32 5: Loading ./FHEM/99_SUNRISE_EL.pm
2014.03.07 13:29:33 5: Loading ./FHEM/99_Utils.pm
2014.03.07 13:29:33 5: Cmd: >attr global motd none<
2014.03.07 13:29:33 5: Cmd: >attr global statefile ./log/fhem.save<
2014.03.07 13:29:33 5: Cmd: >attr global verbose 5<
2014.03.07 13:29:33 5: Cmd: >attr global updateInBackground 1<
2014.03.07 13:29:33 5: Cmd: >define telnetPort telnet 7072 global<
2014.03.07 13:29:33 5: Loading ./FHEM/98_telnet.pm
2014.03.07 13:29:33 3: telnetPort: port 7072 opened
2014.03.07 13:29:33 5: Cmd: >define HMLAN1 HMLAN 192.168.0.6:1000<
2014.03.07 13:29:33 5: Loading ./FHEM/00_HMLAN.pm
2014.03.07 13:29:33 2: HMLAN_Parse: HMLAN1 new condition disconnected
2014.03.07 13:29:33 3: Opening HMLAN1 device 192.168.0.6:1000
2014.03.07 13:29:33 3: HMLAN1 device opened
2014.03.07 13:29:33 5: HMLAN_Send:  HMLAN1 I:C
2014.03.07 13:29:33 5: HMLAN_Send:  HMLAN1 I:Y01,00,
2014.03.07 13:29:33 5: HMLAN_Send:  HMLAN1 I:Y02,00,
2014.03.07 13:29:33 5: HMLAN_Send:  HMLAN1 I:Y03,00,
2014.03.07 13:29:33 5: HMLAN_Send:  HMLAN1 I:T1AAC6A1D,04,00,00000000
2014.03.07 13:29:33 2: HMLAN_Parse: HMLAN1 new condition init
2014.03.07 13:29:33 5: Cmd: >attr HMLAN1 hmId 2576E2<
2014.03.07 13:29:33 5: Cmd: >define WEB FHEMWEB 8083 global<
2014.03.07 13:29:33 5: Loading ./FHEM/01_FHEMWEB.pm
2014.03.07 13:29:33 3: WEB: port 8083 opened
2014.03.07 13:29:33 5: Cmd: >define WEBphone FHEMWEB 8084 global<
2014.03.07 13:29:33 3: WEBphone: port 8084 opened
2014.03.07 13:29:33 5: Cmd: >attr WEBphone stylesheetPrefix ios7<
2014.03.07 13:29:33 5: Cmd: >define WEBtablet FHEMWEB 8085 global<
2014.03.07 13:29:33 3: WEBtablet: port 8085 opened
2014.03.07 13:29:33 5: Cmd: >attr WEBtablet stylesheetPrefix ios7<
2014.03.07 13:29:33 5: Cmd: >define Logfile FileLog ./log/fhem-%Y-%m.log fakelog<
2014.03.07 13:29:33 5: Loading ./FHEM/92_FileLog.pm
2014.03.07 13:29:33 5: Cmd: >define autocreate autocreate<
2014.03.07 13:29:33 5: Loading ./FHEM/98_autocreate.pm
2014.03.07 13:29:33 5: Cmd: >attr autocreate filelog ./log/%NAME-%Y.log<
2014.03.07 13:29:33 5: Cmd: >define eventTypes eventTypes ./log/eventTypes.txt<
2014.03.07 13:29:33 5: Loading ./FHEM/91_eventTypes.pm
2014.03.07 13:29:33 1: Including ./log/fhem.save
2014.03.07 13:29:33 5: Cmd: >setstate HMLAN1 opened<
2014.03.07 13:29:33 5: Cmd: >setstate HMLAN1 2014-03-07 12:03:02 Xmit-Events init:1<
2014.03.07 13:29:33 5: Cmd: >setstate HMLAN1 2014-03-07 12:03:02 cond init<
2014.03.07 13:29:33 5: Cmd: >setstate HMLAN1 2014-03-07 12:03:02 prot_disconnected last<
2014.03.07 13:29:33 5: Cmd: >setstate HMLAN1 2014-03-07 12:03:02 prot_init last<
2014.03.07 13:29:33 5: Cmd: >setstate Logfile active<
2014.03.07 13:29:33 5: Cmd: >setstate autocreate active<
2014.03.07 13:29:33 5: Cmd: >setstate eventTypes active<
2014.03.07 13:29:33 5: Cmd: >setstate global <no definition><
2014.03.07 13:29:33 5: Interface "interface": readings "", getters "", setters ""
2014.03.07 13:29:33 5: Interface "switch": readings "onoff", getters "onoff", setters ""
2014.03.07 13:29:33 5: Interface "switch_active": readings "onoff", getters "onoff", setters ""
2014.03.07 13:29:33 5: Interface "switch_passive": readings "onoff", getters "onoff", setters "on:off"
2014.03.07 13:29:33 5: Interface "dimmer": readings "onoff:level", getters "onoff:level", setters "on:off:dimto:dimup:dimdown"
2014.03.07 13:29:33 5: Interface "temperature": readings "temperature", getters "temperature", setters ""
2014.03.07 13:29:33 5: Interface "humidity": readings "humidity", getters "humidity", setters ""
2014.03.07 13:29:33 5: Interface "wind": readings "wind", getters "wind", setters ""
2014.03.07 13:29:33 5: Interface "power": readings "power:maxPower:energy", getters "power:maxPower:energy", setters ""
2014.03.07 13:29:33 5: Triggering global (1 changes)
2014.03.07 13:29:33 5: Notify loop for global INITIALIZED
2014.03.07 13:29:33 4: eventTypes: Global global INITIALIZED -> INITIALIZED
2014.03.07 13:29:33 0: Server started with 9 defined entities (version $Id: fhem.pl 3872 2013-09-07 11:58:33Z rudolfkoenig $, os linux, user admin, pid 24826)
2014.03.07 13:29:33 5: HMLAN1 Unknown msg >V1309040241201008AA552A150A050201<
2014.03.07 13:29:58 5: HMLAN_Send:  HMLAN1 I:K
2014.03.07 13:29:59 5: HMLAN_Send:  HMLAN1 I:K
2014.03.07 13:30:00 5: HMLAN_Send:  HMLAN1 I:K
2014.03.07 13:30:01 5: HMLAN_Send:  HMLAN1 I:K
2014.03.07 13:30:02 1: 192.168.0.6:1000 disconnected, waiting to reappear
2014.03.07 13:30:02 5: Triggering HMLAN1 (1 changes)
2014.03.07 13:30:02 5: Notify loop for HMLAN1 DISCONNECTED
2014.03.07 13:30:02 4: eventTypes: HMLAN HMLAN1 DISCONNECTED -> DISCONNECTED
2014.03.07 13:30:02 2: HMLAN_Parse: HMLAN1 new condition disconnected
2014.03.07 13:30:02 5: Triggering HMLAN1 (3 changes)
2014.03.07 13:30:02 5: Notify loop for HMLAN1 cond: disconnected
2014.03.07 13:30:02 4: eventTypes: HMLAN HMLAN1 cond: disconnected -> cond: disconnected
2014.03.07 13:30:02 4: eventTypes: HMLAN HMLAN1 Xmit-Events: disconnected:1  -> Xmit-Events: disconnected:.* 
2014.03.07 13:30:02 4: eventTypes: HMLAN HMLAN1 prot_disconnected: last -> prot_disconnected: last
2014.03.07 13:30:07 1: 192.168.0.6:1000 reappeared (HMLAN1)
2014.03.07 13:30:07 5: HMLAN_Send:  HMLAN1 I:A2576E2
2014.03.07 13:30:07 5: HMLAN_Send:  HMLAN1 I:C
2014.03.07 13:30:07 5: HMLAN_Send:  HMLAN1 I:Y01,00,
2014.03.07 13:30:07 5: HMLAN_Send:  HMLAN1 I:Y02,00,
2014.03.07 13:30:07 5: HMLAN_Send:  HMLAN1 I:Y03,00,
2014.03.07 13:30:07 5: HMLAN_Send:  HMLAN1 I:T1AAC6A3F,04,00,00000000
2014.03.07 13:30:07 2: HMLAN_Parse: HMLAN1 new condition init
2014.03.07 13:30:07 5: Triggering HMLAN1 (3 changes)
2014.03.07 13:30:07 5: Notify loop for HMLAN1 cond: init
2014.03.07 13:30:07 4: eventTypes: HMLAN HMLAN1 cond: init -> cond: init
2014.03.07 13:30:07 4: eventTypes: HMLAN HMLAN1 Xmit-Events: init:1  -> Xmit-Events: init:.* 
2014.03.07 13:30:07 4: eventTypes: HMLAN HMLAN1 prot_init: last -> prot_init: last
2014.03.07 13:30:07 5: Triggering HMLAN1 (1 changes)
2014.03.07 13:30:07 5: Notify loop for HMLAN1 CONNECTED
2014.03.07 13:30:07 4: eventTypes: HMLAN HMLAN1 CONNECTED -> CONNECTED
2014.03.07 13:30:07 5: HMLAN1 Unknown msg >V1309040241201008AB552A150A050201<
2014.03.07 13:30:32 5: HMLAN_Send:  HMLAN1 I:K
2014.03.07 13:30:33 5: HMLAN_Send:  HMLAN1 I:K
2014.03.07 13:30:34 5: HMLAN_Send:  HMLAN1 I:K
2014.03.07 13:30:35 5: HMLAN_Send:  HMLAN1 I:K
2014.03.07 13:30:36 1: 192.168.0.6:1000 disconnected, waiting to reappear
2014.03.07 13:30:36 5: Triggering HMLAN1 (1 changes)
2014.03.07 13:30:36 5: Notify loop for HMLAN1 DISCONNECTED
2014.03.07 13:30:36 4: eventTypes: HMLAN HMLAN1 DISCONNECTED -> DISCONNECTED
2014.03.07 13:30:36 2: HMLAN_Parse: HMLAN1 new condition disconnected
2014.03.07 13:30:36 5: Triggering HMLAN1 (3 changes)
2014.03.07 13:30:36 5: Notify loop for HMLAN1 cond: disconnected
2014.03.07 13:30:36 4: eventTypes: HMLAN HMLAN1 cond: disconnected -> cond: disconnected
2014.03.07 13:30:36 4: eventTypes: HMLAN HMLAN1 Xmit-Events: disconnected:1  -> Xmit-Events: disconnected:.* 
2014.03.07 13:30:36 4: eventTypes: HMLAN HMLAN1 prot_disconnected: last -> prot_disconnected: last
2014.03.07 13:30:41 1: 192.168.0.6:1000 reappeared (HMLAN1)
2014.03.07 13:30:41 5: HMLAN_Send:  HMLAN1 I:A2576E2
2014.03.07 13:30:41 5: HMLAN_Send:  HMLAN1 I:C
2014.03.07 13:30:41 5: HMLAN_Send:  HMLAN1 I:Y01,00,
2014.03.07 13:30:41 5: HMLAN_Send:  HMLAN1 I:Y02,00,
2014.03.07 13:30:41 5: HMLAN_Send:  HMLAN1 I:Y03,00,
2014.03.07 13:30:41 5: HMLAN_Send:  HMLAN1 I:T1AAC6A61,04,00,00000000
2014.03.07 13:30:41 2: HMLAN_Parse: HMLAN1 new condition init
2014.03.07 13:30:41 5: Triggering HMLAN1 (3 changes)
2014.03.07 13:30:41 5: Notify loop for HMLAN1 cond: init
2014.03.07 13:30:41 4: eventTypes: HMLAN HMLAN1 cond: init -> cond: init
2014.03.07 13:30:41 4: eventTypes: HMLAN HMLAN1 Xmit-Events: init:1  -> Xmit-Events: init:.* 
2014.03.07 13:30:41 4: eventTypes: HMLAN HMLAN1 prot_init: last -> prot_init: last
2014.03.07 13:30:41 5: Triggering HMLAN1 (1 changes)
2014.03.07 13:30:41 5: Notify loop for HMLAN1 CONNECTED
2014.03.07 13:30:41 4: eventTypes: HMLAN HMLAN1 CONNECTED -> CONNECTED
2014.03.07 13:30:41 5: HMLAN1 Unknown msg >V1309040241201008AC562B150A050201<
2014.03.07 13:31:06 5: HMLAN_Send:  HMLAN1 I:K
2014.03.07 13:31:07 5: HMLAN_Send:  HMLAN1 I:K
2014.03.07 13:31:08 5: HMLAN_Send:  HMLAN1 I:K
2014.03.07 13:31:09 5: HMLAN_Send:  HMLAN1 I:K
2014.03.07 13:31:10 1: 192.168.0.6:1000 disconnected, waiting to reappear
2014.03.07 13:31:10 5: Triggering HMLAN1 (1 changes)
2014.03.07 13:31:10 5: Notify loop for HMLAN1 DISCONNECTED
2014.03.07 13:31:10 4: eventTypes: HMLAN HMLAN1 DISCONNECTED -> DISCONNECTED
2014.03.07 13:31:10 2: HMLAN_Parse: HMLAN1 new condition disconnected
2014.03.07 13:31:10 5: Triggering HMLAN1 (3 changes)
2014.03.07 13:31:10 5: Notify loop for HMLAN1 cond: disconnected
2014.03.07 13:31:10 4: eventTypes: HMLAN HMLAN1 cond: disconnected -> cond: disconnected
2014.03.07 13:31:10 4: eventTypes: HMLAN HMLAN1 Xmit-Events: disconnected:1  -> Xmit-Events: disconnected:.* 
2014.03.07 13:31:10 4: eventTypes: HMLAN HMLAN1 prot_disconnected: last -> prot_disconnected: last
2014.03.07 13:31:15 1: 192.168.0.6:1000 reappeared (HMLAN1)
2014.03.07 13:31:15 5: HMLAN_Send:  HMLAN1 I:A2576E2
2014.03.07 13:31:15 5: HMLAN_Send:  HMLAN1 I:C
2014.03.07 13:31:15 5: HMLAN_Send:  HMLAN1 I:Y01,00,
2014.03.07 13:31:15 5: HMLAN_Send:  HMLAN1 I:Y02,00,
2014.03.07 13:31:15 5: HMLAN_Send:  HMLAN1 I:Y03,00,
2014.03.07 13:31:15 5: HMLAN_Send:  HMLAN1 I:T1AAC6A83,04,00,00000000
2014.03.07 13:31:15 2: HMLAN_Parse: HMLAN1 new condition init
2014.03.07 13:31:15 5: Triggering HMLAN1 (3 changes)
2014.03.07 13:31:15 5: Notify loop for HMLAN1 cond: init
2014.03.07 13:31:15 4: eventTypes: HMLAN HMLAN1 cond: init -> cond: init
2014.03.07 13:31:15 4: eventTypes: HMLAN HMLAN1 Xmit-Events: init:1  -> Xmit-Events: init:.* 
2014.03.07 13:31:15 4: eventTypes: HMLAN HMLAN1 prot_init: last -> prot_init: last
2014.03.07 13:31:15 5: Triggering HMLAN1 (1 changes)
2014.03.07 13:31:15 5: Notify loop for HMLAN1 CONNECTED
2014.03.07 13:31:15 4: eventTypes: HMLAN HMLAN1 CONNECTED -> CONNECTED
2014.03.07 13:31:15 5: HMLAN1 Unknown msg >V1309040241201008AD562B150A050201<

Was mich wundert ist die Unknown msg, V1309040241201008AD562B150A050201. Dieser String (?) wird auch ausgegeben wenn ich mich mit telnet auf das HMLAN verbinde.

perfom habe ich auch laufen lassen, das modul lädt zwar und kündigt seine Dienste an, aber ein Log-Eintrag wird nicht generiert bzw. fhem-interne Probleme scheint es nicht festzustellen.

Ein apptime maxDly nach ca 4min und ein paar Reconnects sieht so aus:

Code Auswählen

fhem> apptime maxDly

                                name             function    max  count    total  average maxDly
            tmr-perfmon_ProcessTimer       HASH(0x2e71a0)      0    142        0     0.00     29 
                tmr-HMLAN_UpdtMsgCnt       UpdtMsg:HMLAN1      0      1        0     0.00     11 
                 tmr-HMLAN_KeepAlive     keepAlive:HMLAN1      1      5        5     1.00     10 keepAlive:HMLAN1
              tmr-FW_closeOldClients                           0      2        0     0.00      9 
            tmr-HMLAN_KeepAliveCheck   keepAliveCk:HMLAN1     12     19       61     3.21      9 keepAliveCk:HMLAN1
                              HMLAN1         HMLAN_Notify      2     16        8     0.50      0 HASH(0x30bed8); HASH(0x30bed8)
                              HMLAN1           HMLAN_Read      0      4        0     0.00      0 
                              HMLAN1          HMLAN_Ready     21      4       77    19.25      0 HASH(0x30bed8)
                             Logfile          FileLog_Log      0     16        0     0.00      0 
                                 WEB            FW_Notify      0     16        0     0.00      0 
                            WEBphone            FW_Notify      0     16        0     0.00      0 
                           WEBtablet            FW_Notify      0     16        0     0.00      0 
                          eventTypes    eventTypes_Notify      1     16       12     0.75      0 HASH(0x518de8); HASH(0x30bed8)
              telnet:127.0.0.1:57548          telnet_Read      1      4        1     0.25      0 HASH(0x244a30)

Und hier noch ein list auf das HMLAN opened

Code Auswählen

fhem> list HMLAN1
Internals:
   DEF        192.168.0.6:1000
   DeviceName 192.168.0.6:1000
   FD         6
   NAME       HMLAN1
   NR         9
   NTFY_ORDER 50-HMLAN1
   PARTIAL    
   STATE      opened
   TYPE       HMLAN
   XmitOpen   1
   assignedIDs 
   assignedIDsCnt 0
   msgKeepAlive dlyMax:0.011 bufferMin:4
   msgLoadEst 1hour:0% 10min steps: 0/0/0/0/0/0
   Readings:
     2014-03-07 16:10:47   Xmit-Events     init:1 
     2014-03-07 16:10:47   cond            init
     2014-03-07 16:10:46   prot_disconnected last
     2014-03-07 16:10:47   prot_init       last
     2014-03-07 16:10:46   prot_timeout    last
   Helper:
     Assids:
     Bm:
       Hmlan_notify:
         cnt        96
         dmx        0
         mAr        HASH(0x30bed8); HASH(0x30bed8)
         max        2
         tot        48
       Hmlan_read:
         cnt        24
         dmx        0
         mAr        
         max        0
         tot        0
       Hmlan_ready:
         cnt        24
         dmx        0
         mAr        HASH(0x30bed8)
         max        21
         tot        451
     K:
       BufMin     4
       DlyMax     0.011
       Next       1394205072.02043
       Start      1394205047.02043
     Log:
       all        0
       sys        0
       ids:
         ARRAY(0x30e5e0)
     Q:
       HMcndN     255
       answerPend 0
       hmLanQlen  1
       keepAliveRec 1
       keepAliveRpt 0
       apIDs:
       Cap:
         0          0
         1          1
         2          0
         3          0
         4          0
         5          0
         last       1
         sum        1
Attributes:
   hmId       2576E2
   hmLanQlen  1_min

und disconnected

Code Auswählen

fhem> list HMLAN1
Internals:
   DEF        192.168.0.6:1000
   DeviceName 192.168.0.6:1000
   NAME       HMLAN1
   NR         9
   NTFY_ORDER 50-HMLAN1
   PARTIAL    
   STATE      disconnected
   TYPE       HMLAN
   XmitOpen   0
   assignedIDs 
   assignedIDsCnt 0
   msgKeepAlive dlyMax:0.011 bufferMin:4
   msgLoadEst 1hour:0% 10min steps: 0/0/0/0/0/0
   Readings:
     2014-03-07 16:12:46   Xmit-Events     disconnected:1 
     2014-03-07 16:12:46   cond            disconnected
     2014-03-07 16:12:46   prot_disconnected last
     2014-03-07 16:12:17   prot_init       last
     2014-03-07 16:12:46   prot_timeout    last
   Helper:
     Assids:
     Bm:
       Hmlan_notify:
         cnt        110
         dmx        0
         mAr        HASH(0x30bed8); HASH(0x30bed8)
         max        2
         tot        56
       Hmlan_read:
         cnt        27
         dmx        0
         mAr        
         max        0
         tot        0
       Hmlan_ready:
         cnt        27
         dmx        0
         mAr        HASH(0x30bed8)
         max        21
         tot        508
     K:
       BufMin     4
       DlyMax     0.011
       Next       1394205190.05686
       Start      1394205165.05686
     Log:
       all        0
       sys        0
       ids:
         ARRAY(0x30e5e0)
     Q:
       HMcndN     253
       answerPend 0
       hmLanQlen  1
       keepAliveRec 0
       keepAliveRpt 3
       apIDs:
       Cap:
         0          0
         1          1
         2          0
         3          0
         4          0
         5          0
         last       1
         sum        1
     Ref:
       kTs        1394205165056
Attributes:
   hmId       2576E2
   hmLanQlen  1_min

Ich werde fhem mit dieser config noch auf meinen Mac laufen lassen um das NAS auszuschliessen, dieses hatte aber während dieser Zeit nicht sehr viel zu tun.
Zu Testzwecken habe ich noch fhem trunk ausgecheckt und laufen lassen, jedoch kein anderes Ergebniss erhalten.

Um Hinweise und Lösungen bin ich natürlich sehr dankbar

Danke & Gruss

martinp876 · 08 März 2014, 15:22:03

dein Problem liegt nicht im Delay, FHRM arbeitet korrekt. Da brauchst du nicht mehr zu suchen. Aber HMLAN antwortet nicht

Zitat2014.03.07 13:29:33 5: HMLAN1 Unknown msg >V1309040241201008AA552A150A050201<
2014.03.07 13:29:58 5: HMLAN_Send: HMLAN1 I:K
2014.03.07 13:29:59 5: HMLAN_Send: HMLAN1 I:K
2014.03.07 13:30:00 5: HMLAN_Send: HMLAN1 I:K
2014.03.07 13:30:01 5: HMLAN_Send: HMLAN1 I:K
2014.03.07 13:30:02 1: 192.168.0.6:1000 disconnected, waiting to reappear

4 mal keepalive aber keine Antwort
Die Antwort muesste so aussehen:

Zitat2014.03.08 15:16:54.209 0: HMLAN_Send: iohl1 I:K
2014.03.08 15:16:54.217 0: HMLAN_Parse: iohl1 V:03C1 sNo:IEQ0244337 d:1743BF O:1743BF t:09538B35 IDcnt:0010

Da der Ping funktioniert stellt sich die Frage, warum das keepalive nicht gesendet - oder zumindest nicht beantwortet wird. Eine firewall oder aehnlich ist nicht aktiv?

Gruss Martin

el_migu_el · 09 März 2014, 20:54:46

Hallo Martin,

danke für Deine Antwort und den Hinweis, welcher mich - bislang - zum Ziel führte.
Nachdem ich mit Wireshark den Traffic gesnifft habe und keine Requests an HMLanfand, sehr wohl aber wenn ich mich manuell via Telnet beim HMLan anmeldete,
ging ich quasi wieder auf Feld 1 und versuchte AES zu deaktivieren.
Das führte dann dazu das die Reconnects verschwanden.
Komischerweise konnte ich nun auf einmal auch ohne AES verbinden, was vorher nicht ging(?), jedenfalls lat fhem-log.

Danke nochmals

wtue · 18 März 2014, 09:06:48

Hallo Forum,
in einem Post weiter oben habe ich geschrieben

ZitatMit den hier beschriebenen Methoden konnte 99_perfmon.pm und apptime konnte ich nicht wirklich einen "Schuldigen" ausmachen. Habe dieses Problem aber erstmal zurückgestellt weil ich noch einen Rollenaktor hatte, den ich per FHEM nicht ansprechen konnte. Der Aktor war mal richtig angelernt und hat auch auf FHEM Befehle reagiert. Aber, warum auch immer er tat's nicht mehr. Ich ging schon von einem Defekt aus, habe aber sicherheitshalber noch mal die Anlerntaste gedrückt und angelernt mit set HMLAN1 hmPairSerial KEQXXXXXXX . Was soll ich sagen, der Aktor funktioniert und meine Unterbrechungen sind auch weg. Das Modul perfmon mäkelt zwar gelegengtlich, aber alles ist gut.

Es ist nicht alles gut. Das Problem besteht weiter.

In der Ausgangssituation ist der HMLAN über einem Switch an der FB angeschlossen. Mit den, hier mehrfach beschriebenen Methoden kam ich nicht weiter. Ich habe den HMLAN jetzt ins Wohnzimmer umgezogen. Dort hängt er an einer FB7270 (ohne FHEM). Diese FB ist über einen Powerlineadapter ins Netz integriert und dient mir als AP im Wohnzimmer.

Mit dem Umzug ins Wohnzimmer hat sich die Situation verbessert. Ich habe im normalen Betrieb 1-2 Disconnect am Tag. Nach einer Woche bin ich recht zufrieden. Aber woran kann es liegen? An der kürzeren Funkstrecke zu den meisten meiner Aktoren? Wohl kaum. So wie ich das jetzt sehe handelt es sich um ein schnödes Netzwerkproblem des HMLAN. Im Wohnzimmer hängt er an einem 100 MBit Port der FB und Powerline ist noch mal langsamer, dass will ich aber garnicht betrachten. In der Ausgangssituation hing HMLAN an einem GigaBit Port meines Switches im Büro.

Also gut, langes Netzwerkkabel vom Büro ins Wohnzimmer und siehe da die Probleme treten wieder massiv auf. Ich habe wieder Timeouts in kurzen Abständen. Gelegentlich habe ich 4 Wiederholungen und dann kommt doch eine Antwort.

Code Auswählen

2014.03.18 07:58:37.504 0: HMLAN_Parse: HMLAN1 V:03C1 sNo:KEQ0851629 d:23A33B O:F11034 t:01FCF8DB IDcnt:0000
2014.03.18 07:59:02.501 0: HMLAN_Send:  HMLAN1 I:K
2014.03.18 07:59:02.509 0: HMLAN_Parse: HMLAN1 V:03C1 sNo:KEQ0851629 d:23A33B O:F11034 t:01FD5A8C IDcnt:0000
2014.03.18 07:59:27.507 0: HMLAN_Send:  HMLAN1 I:K
2014.03.18 07:59:28.513 0: HMLAN_Send:  HMLAN1 I:K
2014.03.18 07:59:29.518 0: HMLAN_Send:  HMLAN1 I:K
2014.03.18 07:59:30.524 0: HMLAN_Send:  HMLAN1 I:K
2014.03.18 07:59:30.574 0: HMLAN_Parse: HMLAN1 V:03C1 sNo:KEQ0851629 d:23A33B O:F11034 t:01FDC831 IDcnt:0000
2014.03.18 07:59:30.581 0: HMLAN_Parse: HMLAN1 V:03C1 sNo:KEQ0851629 d:23A33B O:F11034 t:01FDC835 IDcnt:0000
2014.03.18 07:59:30.583 0: HMLAN_Parse: HMLAN1 V:03C1 sNo:KEQ0851629 d:23A33B O:F11034 t:01FDC837 IDcnt:0000
2014.03.18 07:59:30.585 0: HMLAN_Parse: HMLAN1 V:03C1 sNo:KEQ0851629 d:23A33B O:F11034 t:01FDC838 IDcnt:0000
2014.03.18 07:59:55.529 0: HMLAN_Send:  HMLAN1 I:K
2014.03.18 07:59:55.536 0: HMLAN_Parse: HMLAN1 V:03C1 sNo:KEQ0851629 d:23A33B O:F11034 t:01FE29B8 IDcnt:0000

Hier hats gerade noch geklappt.

Code Auswählen

2014.03.18 08:01:10.544 0: HMLAN_Send:  HMLAN1 I:K
2014.03.18 08:01:10.553 0: HMLAN_Parse: HMLAN1 V:03C1 sNo:KEQ0851629 d:23A33B O:F11034 t:01FF4ECB IDcnt:0000
2014.03.18 08:01:13.697 0: HMLAN_Parse: HMLAN1 R:E21F320   stat:0000 t:01FF5B0D d:FF r:FFC2     m:42 8610 21F320 000000 0A88DF0E0020
2014.03.18 08:01:35.550 0: HMLAN_Send:  HMLAN1 I:K
2014.03.18 08:01:36.556 0: HMLAN_Send:  HMLAN1 I:K
2014.03.18 08:01:37.561 0: HMLAN_Send:  HMLAN1 I:K
2014.03.18 08:01:38.566 0: HMLAN_Send:  HMLAN1 I:K
2014.03.18 08:01:39.570 1: HMLAN_Parse: HMLAN1 new condition timeout
2014.03.18 08:01:39.582 1: 172.16.2.43:1000 disconnected, waiting to reappear
2014.03.18 08:01:39.585 1: HMLAN_Parse: HMLAN1 new condition disconnected
2014.03.18 08:02:41.011 1: 172.16.2.43:1000 reappeared (HMLAN1)
2014.03.18 08:02:41.013 0: HMLAN_Send:  HMLAN1 I:AF11034
2014.03.18 08:02:41.015 0: HMLAN_Send:  HMLAN1 I:C
2014.03.18 08:02:41.017 0: HMLAN_Send:  HMLAN1 I:Y01,00,
2014.03.18 08:02:41.019 0: HMLAN_Send:  HMLAN1 I:Y02,00,
2014.03.18 08:02:41.021 0: HMLAN_Send:  HMLAN1 I:Y03,00,
2014.03.18 08:02:41.024 0: HMLAN_Send:  HMLAN1 I:T1ABA9E01,04,00,00000000
2014.03.18 08:02:41.026 1: HMLAN_Parse: HMLAN1 new condition init
2014.03.18 08:02:41.039 0: HMLAN_Send:  HMLAN1 S:SD3FFCFD2 stat:  00 t:00000000 d:01 r:D3FFCFD2 m:99 8112 F11034 000001 
2014.03.18 08:02:41.055 0: HMLAN_Parse: HMLAN1 V:03C1 sNo:KEQ0851629 d:23A33B O:F11034 t:0200B039 IDcnt:0000
2014.03.18 08:02:41.057 0: HMLAN_Parse: HMLAN1 V:03C1 sNo:KEQ0851629 d:23A33B O:F11034 t:01FFC405 IDcnt:0000
2014.03.18 08:02:41.060 0: HMLAN_Parse: HMLAN1 V:03C1 sNo:KEQ0851629 d:23A33B O:F11034 t:01FFC409 IDcnt:0000
2014.03.18 08:02:41.062 0: HMLAN_Parse: HMLAN1 V:03C1 sNo:KEQ0851629 d:23A33B O:F11034 t:01FFC40A IDcnt:0000
2014.03.18 08:02:41.066 0: HMLAN_Parse: HMLAN1 V:03C1 sNo:KEQ0851629 d:23A33B O:F11034 t:01FFC40B IDcnt:0000
2014.03.18 08:02:41.070 0: HMLAN_Parse: HMLAN1 R:RD3FFCFD2 stat:0002 t:00000000 d:FF r:7FFF     m:99 8112 F11034 000001 
2014.03.18 08:02:41.072 1: HMLAN_Parse: HMLAN1 new condition ok
2014.03.18 08:03:06.040 0: HMLAN_Send:  HMLAN1 I:K
2014.03.18 08:03:06.048 0: HMLAN_Parse: HMLAN1 V:03C1 sNo:KEQ0851629 d:23A33B O:F11034 t:02011204 IDcnt:0000
2014.03.18 08:03:17.458 0: HMLAN_Parse: HMLAN1 R:E21FECE   stat:0000 t:02013E91 d:FF r:FFB8     m:04 8610 21FECE 000000 0A88B20E0018

Es geht aber auch schief.

Zum sniffen mit WireShark habe ich einen uralt Hub mit 10 MBit eingebaut. Also FB --> GigaBit Switch --> 10MBit Hub --> HMLAN.

Seit einer halben Stunde läuft das so ohne Probleme. In der Situation bringt sniffen nichts. Die Zeit ist natürlich viel zu kurz um zu behaupten das es das jetzt war. Ich wollte das jetzt nur mal los werden. Habe ich mich vergallopiert oder könnt ihr mir folgen. Auch Martin hatte ja schon die These, dass es eigentlich kein FHEM Problem ist, weil die gelegentlichen Ausreisser von perfmon die vielen Unterbrechungen nicht erklären.

Ich bin gespannt auf eure Meinung.

Werner

martinp876 · 18 März 2014, 09:28:45

ZitatSo wie ich das jetzt sehe handelt es sich um ein schnödes Netzwerkproblem

ja

Zitatdes HMLAN

warum? Eher dein Netzwerk. Der HMLAN antwortet immer prompt, das ist bei allen anderen so, also auch bei dir.

Zitatlanges Netzwerkkabel vom Büro ins Wohnzimmer und siehe da die Probleme treten wieder massiv auf

kann es sein, dass die Verbindung so schlecht ist, dass ständig wiederholt wird?

ZitatGelegentlich habe ich 4 Wiederholungen und dann kommt doch eine Antwort.

fast richtig. Es kommen 4 Antworten. Es sind nur alle verzögert - um sage und schreibe 3 sec! Und dann kommen alle! Etwas in deinem Netzwerk macht ein eigenes timing - sendet nur blockweise... aus irgend einem Grund.

ZitatZum sniffen mit WireShark habe ich einen uralt Hub mit 10 MBit eingebaut.

Du solltest versuchen an verschiedenen Stellen im Netz zu sniffen um zu sehen, wer hier bummelt.

wtue · 18 März 2014, 10:16:39

Hallo Martin,
ich habe mich bestimmt nicht richtig ausgedrückt.

Ich bin auf dem Tripp, dass das Gerät HM-CFG-LAN nicht mit Giga-Bit Ports zurecht kommt. Bei sonst gleichem Aufbau, (langes Kabel zum Wohnzimmer etwa 10 Meter) habe ich keine Probleme, wenn ich einen langsamen Hub zusätzlich dazwischen hänge. Der Grund warum ich den Hub eingebaut habe liegt am Sniffen. Im Netzwerk sehe ich den Traffic zwischen FHEM und dem Device nicht an den unbeteiligten Ports des Switch. Mein Switch zu Hause läßt sich nicht managen und ich kann keinen Monitorport einrichten. Am Hub kann ich aber den Datenverkehr an allen Ports sehen. Bei mir im Netz ist sonst nicht viel los und die 10 Meter von meinem häuslichen Arbeitszimmer zum Wohnzimmer sind sicher auch nicht das Problem. Ich bringe mir mal einen inteligenteren Switch von meinem Arbeitgeber mit. Dann kann ich versuchen meine These zu beweisen.

Code Auswählen


2014.03.18 08:03:56.049 0: HMLAN_Send:  HMLAN1 I:K
2014.03.18 08:03:57.055 0: HMLAN_Send:  HMLAN1 I:K
2014.03.18 08:03:58.059 0: HMLAN_Send:  HMLAN1 I:K
2014.03.18 08:03:59.064 0: HMLAN_Send:  HMLAN1 I:K
2014.03.18 08:03:59.117 0: HMLAN_Parse: HMLAN1 V:03C1 sNo:KEQ0851629 d:23A33B O:F11034 t:0201E15A IDcnt:0000
2014.03.18 08:04:03.043 0: HMLAN_Parse: HMLAN1 V:03C1 sNo:KEQ0851629 d:23A33B O:F11034 t:0201F0AB IDcnt:0000
2014.03.18 08:04:03.045 0: HMLAN_Parse: HMLAN1 V:03C1 sNo:KEQ0851629 d:23A33B O:F11034 t:0201F0AC IDcnt:0000
2014.03.18 08:04:03.047 0: HMLAN_Parse: HMLAN1 V:03C1 sNo:KEQ0851629 d:23A33B O:F11034 t:0201F0AD IDcnt:0000
2014.03.18 08:04:24.069 0: HMLAN_Send:  HMLAN1 I:K

Ich lese das so: Aus Fhem heraus wird das Gerät angesprochen. Es kommt keine Antwort innerhalb einer Sekunde und das Telegramm wird 3 mal wiederholt. Erst dann kommen die Antworten. Gerade noch rechtzeitig. Interpretiere ich das jetzt komplett falsch?

martinp876 · 18 März 2014, 12:17:01

deine Interpretation des Ablaufs ist korrekt.
Ich habe das Port des HMLAN auf 1GB gesetzt. Es schaltet nicht um, was sinn macht. Was will ein HMLAN mit 1GBit? Es macht 100MBit und läuft zuverlässig.
Sollte dein Router immer wieder auf die Idee kommen 1GB zu probieren kann es zu Problemen führen.
LAN AutoNegotiate führt immer zu (geringem) datenverlust, was die Erfahrung zeigt. Evtl versucht dein Router etwas zu viel.

Gruss Martin

wtue · 18 März 2014, 13:15:00

ZitatIch habe das Port des HMLAN auf 1GB gesetzt.

Ich nehme mal an, dass du das im Switch gemacht hast. Bei dem Config-Tool des HMLAN finde ich dazu keine Einstellmöglichkeit. Da werde ich mir einen managebaren Switch kaufen müssen um eine feste Geschwindigkeit einstellen zu können. Oder den "doofen" Hub beibehalten. Der kann nur 10MBit, was ja vollkommen reicht.