CUNO timing varinazen

Begonnen von martinp876, 17 Dezember 2013, 15:18:21

Vorheriges Thema - Nächstes Thema

martinp876

Hi,

die CUNO2 hat nach vorliegenden Daten eine recht hohe timing Varianz. Da ich keine Besitze kann ich es nicht selbst prüfen.
Was der Grund ist (ethernet oder CUNO2 FW) kann ich nicht sagen.
Der Fehler tritt im HM mode auf.
HM lebt von einem genauen uns stabilen Timing - CUNO2 besitzer konnen aktuell wohl kein HM betreiben (jedenfalls kenne ich keinen)

Die Frage ist also
- wie gross ist der delay und die Varianz beim senden von iowrite bis es in der Luft ist?
- wie gross ist der delay und die Varianz beim Empfangen von der Luft bis zum Read?

Zum messen brauch man am sicher ein weiteres Device, das monitoren kann.

Eine CUL macht keine Probleme - das timing ist also eingermassen verlässlich.
Ein HMLAN liefert präzise Zeitstempel aus der Box - wäre auch eine Option zum Messen

Da ich keine CUNO habe (und aktuell auch keine brauche, somit keine kaufe) kann ich bei den Messungen leider nicht helfen. Aber ihr habt sicher das Equipment

Gruss Martin

rudolfkoenig

ZitatAber ihr habt sicher das Equipment
Bin gespannt, wer sich angesprochen fuehlt.

martinp876

ist keiner für CUNO assigned? Schade. Wer hat es den gebaut? Ich kann leider nicht....

rudolfkoenig

Sei vorsichtig. "kann" ist evtl. das falsche Wort :)

martinp876

ist aber so. hätte ich eine CUNO wäre es erledigt - also zumindest das messen. Ist ja nicht wirklich schwer... ok, ein paar Messungen zur Kalibrierung, dann die Wert erfassen.
Da ich aber aktuell keine CUNO brauche kaufe ich auch keine - klar. Und ohne CUNO ist es echt problematisch.   :( 

rudolfkoenig

Hallo Martin,

wenn deine Post-Adresse im letzten Jahr sich nicht geaendert hat, dann hast du demnaechst keine Ausrede mehr: busware schickt dir ein Geraet zu.

Gruss,
  Rudi

martinp876

danke - muss ich eben neue Ausreden suchen ;D

holzwurm83

Hallo Martin,

konntest du schon test machen?
- Fhem auf einem MacMini Server
- CUL; HMLAN; CUNO2 für FS20; HM-Wired RS485 LAN Gateway
- HMW_Sen_SC_12_FM; HMW_LC_Sw2_DR; HMW_LC_Bl1_DR; HMW_IO_12_Sw7; HMW_IO_12_Sw14_DR; HMW_IO_12_FM; HBW_1W_T10
- HM-TC-IT-WM-W-EU; HM-CC-RT-DN

martinp876


martinp876

Hi,

wen's interessiert, hier ein paar Messergebnisse:
Im Test
FB 7390, CUNO, CUL, HMLAN.
Gemessen wurde aktuell nur die Empfangsrichtung. Die Ethernet-packete sowie Zeitstempel mit FHEM wurden erfasst.
Die Zeitstempel der Ethernet Pakete scheinen verlässlich.

a) Delay zwischen Ethernet Paket und FHEM praser ist zwischen 2 und 135ms im Test
b) delay CUNO Ethernet bis Parser ist oft kürzer.
  Grund ist, dass die CUL als erste empfängt, die Pakete dispatched und verarbeitet werden. Das verzögert die Bearbeitung des IO Devices. CUNO hingegen ist durch die eigene Verzögerung so langsam, dass hier alles erledigt ist. Die Pakete werden sofort bearbeitet. HMLAN Pakete hätte die gleiche Geschwindigkeit
c) Messages der CUNO haben bereits am Ethernet einen Delay in der Größenordnung von 95 bis 245ms.
=> sowohl absoluter delay (min 100ms) als auch Varianz (-0 +150ms) sind nicht für präzises Timing nutzbar
d) HMLAN sendet einen Zeitstempel, der ein Rückrechnen zur Empfangszeit in der Luft erlaubt und einen Ausgleich aller folgenden Delays ermöglicht (Ethernet/FHEM/system). Das ermöglicht zumindest das zeitgerechte Senden der Massage von FHEM. Delays der Sendepakete durch Ethernet können nicht ausgeglichen werden (vielleicht doch?)

Eine CUNO ist daher aktuell nicht für timings nutzbar, die Reaktionszeiten kleiner 250ms benötigen. Unter Berücksichtigung vorhandener  Processing Zeiten in FHEM sollte man noch einmal 70ms addieren.
==> eine CUNO ist für HM aktuell nicht  präzise genug.

HM benötigt Reaktionen in max 100ms. Varianzen von 50ms können evtl tragbar sein (Annahme)
die Korrektur der Zeiten bei HMLAN scheint gut zu funktionieren.
CUL ist im Gegensatz zu CUNO weit schneller und präziser.

Legende
iocu1: CUL
iocn1: CUNO
iohl1: hmlan

Gruss Martin


[font=courier]dly1: ethernet -> parser
dly2: air -> parser
FHEM time                                                                          Ethernet time    dly1  dly2
16:20:49.312  CUL_Parse:   iocu1           A 0B 2E A240 212291 1743BF 020B                         
16:20:49.433  HMLAN_Parse: iohl1 t:0A1A843E   m:2E A240 212291 1743BF 020B        .16:20:49.317535  116   
16:20:49.512  CUL_Parse:   iocn1           A 0B 2E A240 212291 1743BF 020B        .16:20:49.510040  2     195
16:20:49.562  CUL_Parse:   iocu1           A 0B 2F A240 212291 1743BF 020B                               
16:20:49.638  HMLAN_Parse: iohl1 t:0A1A8538   m:2F A240 212291 1743BF 020B        .16:20:49.567533  71   
16:20:49.761  CUL_Parse:   iocn1           A 0B 2F A240 212291 1743BF 020B        .16:20:49.758462  3     194
16:20:49.813  CUL_Parse:   iocu1           A 0B 30 A240 212291 1743BF 020B                               
16:20:49.884  HMLAN_Parse: iohl1 t:0A1A8633   m:30 A240 212291 1743BF 020B        .16:20:49.818489  66   
16:20:50.008  CUL_Parse:   iocn1           A 0B 30 A240 212291 1743BF 020B        .16:20:50.006772  2     190
16:20:51.786  HMLAN_Parse: iohl1 t:0A1A8D96   m:88 A258 172A85 150B94 000C        .16:20:51.709189  77   
16:20:51.807  CUL_Parse:   iocn1           A 0B 88 A258 172A85 150B94 000C        .16:20:51.744691  63    98
16:20:51.833  CUL_Parse:   iocu1           A 0E 88 8202 150B94 172A85 01010A0020                         
16:20:51.916  HMLAN_Parse: iohl1 t:0A1A8E17   m:88 8202 150B94 172A85 01010A0020  .16:20:51.838326  78   
16:20:51.996  CUL_Parse:   iocn1           A 0E 88 8202 150B94 172A85 01010A0020  .16:20:51.993130  3     158
16:20:54.233  CUL_Parse:   iocu1           A 0B 31 A240 212291 1743BF 0100                               
16:20:54.360  HMLAN_Parse: iohl1 t:0A1A9778   m:31 A240 212291 1743BF 0100        .16:20:54.238893  122   
16:20:54.482  CUL_Parse:   iocn1           A 0B 31 A240 212291 1743BF 0100        .16:20:54.475829  7     244
16:20:54.503  HMLAN_Parse: iohl1 t:0A1A9873   m:32 A240 212291 1743BF 0100        .16:20:54.489844  14   
16:20:54.625  CUL_Parse:   iocu1           A 0B 32 A240 212291 1743BF 0100                               
16:20:54.733  CUL_Parse:   iocn1           A 0B 32 A240 212291 1743BF 0100        .16:20:54.724219  9     244
16:20:54.751  HMLAN_Parse: iohl1 t:0A1A996E   m:33 A240 212291 1743BF 0100        .16:20:54.740779  11   
16:20:54.819  CUL_Parse:   iocu1           A 0B 33 A240 212291 1743BF 0100                               
16:20:54.985  CUL_Parse:   iocn1           A 0B 33 A240 212291 1743BF 0100        .16:20:54.972391  13    245
16:20:59.841  CUL_Parse:   iocu1           A 0B 34 A240 212291 1743BF 0300                               
16:20:59.981  HMLAN_Parse: iohl1 t:0A1AAD60   m:34 A240 212291 1743BF 0300        .16:20:59.846196  135   
16:20:59.984  HMLAN_corret      dly:144                                       calc 16:20:59.840           
16:21:00.008  CUL_Parse:   iocn1           A 0B 34 A240 212291 1743BF 0300        .16:20:59.938249  70    162
16:21:00.092  CUL_Parse:   iocu1           A 0B 35 A240 212291 1743BF 0300                               
16:21:00.170  HMLAN_Parse: iohl1 t:0A1AAE5B   m:35 A240 212291 1743BF 0300        .16:21:00.097131  73   
16:21:00.173  HMLAN_corret      dly:82                                        calc 16:21:00.091           
16:21:00.210  CUL_Parse:   iocn1           A 0B 35 A240 212291 1743BF 0300        .16:21:00.186520  24    113
16:21:00.342  CUL_Parse:   iocu1           A 0B 36 A240 212291 1743BF 0300                               
16:21:00.415  HMLAN_Parse: iohl1 t:0A1AAF56   m:36 A240 212291 1743BF 0300        .16:21:00.348101  67   
16:21:00.418  HMLAN_corret       dly:75                                       calc 16:21:00.342           
16:21:00.443  CUL_Parse:   iocn1           A 0B 36 A240 212291 1743BF 0300        .16:21:00.434859  9     95[/font]

rene

#10
Ich mag mich zur Bekräftigung hier kurz anschließen. Es hat mir letzte Nacht den Schlaf geraubt, dass die Thermostate (HM-CC-RT-DN) sich partout nicht steuern lassen wollten, trotz korrektem Ack und empfangener Readings. Dank der Tipps hier, hab ich dann heute den CUNO2 via USB betrieben (was suboptimal ist, weil ich die IR_RX eigentlich an einer anderen Stelle benötige) und damit läuft es auch bei mir. Aber zum eigentlichen Threadinhalt. Hier meine Timings aus dem Log (device CUNO via USB, device CNET via Ethernet - selbes Gerät jeweils)


2014.01.02 21:24:55.367 5: CUNO dispatch A0FB9861022262B0000000A245F100058::-46:CUNO
2014.01.02 21:24:55.445 5: CNET dispatch A0FB9861022262B0000000A245F100058::-46:CNET

2014.01.02 21:25:01.988 5: CUNO dispatch A0F1C86102322A20000000A24770F0066::-47:CUNO
2014.01.02 21:25:02.162 5: CNET dispatch A0F1C86102322A20000000A24770F0066::-47:CNET

2014.01.02 21:25:02.269 5: CUNO dispatch A0A0280022322A2F1123400::-47:CUNO
2014.01.02 21:25:02.422 5: CNET dispatch A0A0280022322A2F1123400::-47:CNET

2014.01.02 21:25:02.577 5: CUNO dispatch A1A03A0102322A2F11234020100020109010AF10B120C340E0A0F00::-47:CUNO
2014.01.02 21:25:02.660 5: CNET dispatch A1A03A0102322A2F11234020100020109010AF10B120C340E0A0F00::-47:CNET

2014.01.02 21:25:02.833 5: CUNO dispatch A180480102322A2F1123402110012151600180019001A000000::-47:CUNO
2014.01.02 21:25:02.909 5: CNET dispatch A180480102322A2F1123402110012151600180019001A000000::-47:CNET

2014.01.02 21:25:03.126 5: CUNO dispatch A0E0480102322A2F112340100000000::-47:CUNO
2014.01.02 21:25:03.157 5: CNET dispatch A0E0480102322A2F112340100000000::-47:CNET

2014.01.02 21:25:03.417 5: CUNO dispatch A0E0580102322A2F112340208000000::-47:CUNO
2014.01.02 21:25:03.655 5: CNET dispatch A0E0580102322A2F112340208000000::-47:CNET

2014.01.02 21:25:03.709 5: CUNO dispatch A0E0680102322A2F112340208000000::-47:CUNO
2014.01.02 21:25:03.904 5: CNET dispatch A0E0680102322A2F112340208000000::-47:CNET

2014.01.02 21:25:04.016 5: CUNO dispatch A1A07A0102322A2F1123403012A22093D18030016073000640F0500::-47:CUNO
2014.01.02 21:25:04.162 5: CNET dispatch A1A07A0102322A2F1123403012A22093D18030016073000640F0500::-47:CNET

2014.01.02 21:25:04.274 5: CUNO dispatch A1A08A0102322A2F1123403100000098E4448550845204520452045::-47:CUNO
2014.01.02 21:25:04.420 5: CNET dispatch A1A08A0102322A2F1123403100000098E4448550845204520452045::-47:CNET

2014.01.02 21:25:04.532 5: CUNO dispatch A1A09A0102322A2F11234031F204520452045204520452045204520::-47:CUNO
2014.01.02 21:25:04.677 5: CNET dispatch A1A09A0102322A2F11234031F204520452045204520452045204520::-47:CNET

2014.01.02 21:25:04.790 5: CUNO dispatch A1A0AA0102322A2F11234032E444855084520452045204520452045::-47:CUNO
2014.01.02 21:25:04.908 5: CNET dispatch A1A0AA0102322A2F11234032E444855084520452045204520452045::-47:CNET

2014.01.02 21:25:05.048 5: CUNO dispatch A1A0BA0102322A2F11234033D20452045204520452045204448546C::-47:CUNO
2014.01.02 21:25:05.148 5: CNET dispatch A1A0BA0102322A2F11234033D20452045204520452045204448546C::-47:CNET

2014.01.02 21:25:05.308 5: CUNO dispatch A1A0CA0102322A2F11234034C44CC55084520452045204520452045::-47:CUNO
2014.01.02 21:25:05.396 5: CNET dispatch A1A0CA0102322A2F11234034C44CC55084520452045204520452045::-47:CNET

2014.01.02 21:25:05.565 5: CUNO dispatch A1A0DA0102322A2F11234035B204520452045204448546C44CC5508::-47:CUNO
2014.01.02 21:25:05.645 5: CNET dispatch A1A0DA0102322A2F11234035B204520452045204448546C44CC5508::-47:CNET

2014.01.02 21:25:05.824 5: CUNO dispatch A1A0EA0102322A2F11234036A452045204520452045204520452045::-47:CUNO
2014.01.02 21:25:05.894 5: CNET dispatch A1A0EA0102322A2F11234036A452045204520452045204520452045::-47:CNET

2014.01.02 21:25:06.082 5: CUNO dispatch A1A0FA0102322A2F1123403792045204448546C44CC550845204520::-47:CUNO
2014.01.02 21:25:06.143 5: CNET dispatch A1A0FA0102322A2F1123403792045204448546C44CC550845204520::-47:CNET

2014.01.02 21:25:06.340 5: CUNO dispatch A1A10A0102322A2F112340388452045204520452045204520452044::-47:CUNO
2014.01.02 21:25:06.392 5: CNET dispatch A1A10A0102322A2F112340388452045204520452045204520452044::-47:CNET

2014.01.02 21:25:06.599 5: CUNO dispatch A1A11A0102322A2F11234039748546C44CC55084520452045204520::-47:CUNO
2014.01.02 21:25:06.640 5: CNET dispatch A1A11A0102322A2F11234039748546C44CC55084520452045204520::-47:CNET

2014.01.02 21:25:06.857 5: CUNO dispatch A1A12A0102322A2F1123403A6452045204520452045204448546C44::-47:CUNO
2014.01.02 21:25:06.889 5: CNET dispatch A1A12A0102322A2F1123403A6452045204520452045204448546C44::-47:CNET

2014.01.02 21:25:07.115 5: CUNO dispatch A1A13A0102322A2F1123403B5CC5508452045204520452045204520::-47:CUNO
2014.01.02 21:25:07.138 5: CNET dispatch A1A13A0102322A2F1123403B5CC5508452045204520452045204520::-47:CNET

2014.01.02 21:25:07.370 5: CUNO dispatch A1714A0102322A2F1123403C44520452045200F1E1E0F1E1E::-47:CUNO
2014.01.02 21:25:07.387 5: CNET dispatch A1714A0102322A2F1123403C44520452045200F1E1E0F1E1E::-47:CNET

2014.01.02 21:25:07.609 5: CUNO dispatch A0B1580102322A2F112340300::-47:CUNO
2014.01.02 21:25:07.640 5: CNET dispatch A0B1580102322A2F112340300::-47:CNET


Man sieht also auch hier durchschnittlich über 100ms Latenz auf dem LAN interface. Welches allerdings mit ICMP Laufzeiten von unter 5ms nicht am Netzwerk liegt.


64 bytes from 192.168.2.102: icmp_seq=1 ttl=64 time=4.48 ms
64 bytes from 192.168.2.102: icmp_seq=2 ttl=64 time=4.55 ms
64 bytes from 192.168.2.102: icmp_seq=3 ttl=64 time=4.54 ms
64 bytes from 192.168.2.102: icmp_seq=4 ttl=64 time=4.55 ms
64 bytes from 192.168.2.102: icmp_seq=5 ttl=64 time=4.51 ms
64 bytes from 192.168.2.102: icmp_seq=6 ttl=64 time=4.41 ms
64 bytes from 192.168.2.102: icmp_seq=7 ttl=64 time=4.47 ms
64 bytes from 192.168.2.102: icmp_seq=8 ttl=64 time=4.60 ms
64 bytes from 192.168.2.102: icmp_seq=9 ttl=64 time=4.46 ms


Ich hab mich jetzt nicht durch den Code gewühlt, ob die Verarbeitung der CUNO messages den Empfang der CNET messages zeitlich beeinflusst. Sollte das der Fall sein, dann sind meine Logs natürlich unbrauchbar, getreu dem Motto "Wer misst, misst Mist".

Gleich nochmal nachgemessen, um nicht zuviel Mist zu messen:

2014.01.03 09:00:51.502 5: CNET dispatch A1A20A0102224A7F11234036A452045204520452045204520452045::-66.5:CNET
T 2014/01/03 09:00:51.501287 192.168.2.102:2323 -> 192.168.2.106:50996 [AP]  A1A20A0102224A7F11234036A4520452045204520452045204520450F..                                                                           

2014.01.03 09:00:51.752 5: CNET dispatch A1A21A0102224A7F1123403792045204448546C44CC550845204520::-66:CNET
T 2014/01/03 09:00:51.750009 192.168.2.102:2323 -> 192.168.2.106:50996 [AP]  A1A21A0102224A7F1123403792045204448546C44CC55084520452010..                                                                           

2014.01.03 09:00:52.001 5: CNET dispatch A1A22A0102224A7F112340388452045204520452045204520452044::-66:CNET
T 2014/01/03 09:00:51.998840 192.168.2.102:2323 -> 192.168.2.106:50996 [AP]  A1A22A0102224A7F11234038845204520452045204520452045204410..                                                                           

2014.01.03 09:00:52.249 5: CNET dispatch A1A23A0102224A7F11234039748546C44CC55084520452045204520::-66.5:CNET
T 2014/01/03 09:00:52.247572 192.168.2.102:2323 -> 192.168.2.106:50996 [AP]  A1A23A0102224A7F11234039748546C44CC550845204520452045200F..                                                                           

2014.01.03 09:00:52.498 5: CNET dispatch A1A24A0102224A7F1123403A6452045204520452045204448546C44::-66.5:CNET
T 2014/01/03 09:00:52.496338 192.168.2.102:2323 -> 192.168.2.106:50996 [AP]  A1A24A0102224A7F1123403A6452045204520452045204448546C440F..                                                                           

2014.01.03 09:00:52.747 5: CNET dispatch A1A25A0102224A7F1123403B5CC5508452045204520452045204520::-66.5:CNET
T 2014/01/03 09:00:52.745104 192.168.2.102:2323 -> 192.168.2.106:50996 [AP]  A1A25A0102224A7F1123403B5CC55084520452045204520452045200F..                                                                           

2014.01.03 09:00:52.996 5: CNET dispatch A1726A0102224A7F1123403C44520452045200F1E1E0F1E1E::-66.5:CNET
T 2014/01/03 09:00:52.993871 192.168.2.102:2323 -> 192.168.2.106:50996 [AP]  A1726A0102224A7F1123403C44520452045200F1E1E0F1E1E0F..                                                                                 

2014.01.03 09:00:53.244 5: CNET dispatch A0B2780102224A7F112340300::-66:CNET
T 2014/01/03 09:00:53.241967 192.168.2.102:2323 -> 192.168.2.106:50996 [AP]  A0B2780102224A7F11234030010..                                                                                                         

2014.01.03 09:01:06.931 5: CNET dispatch A0FCC861022262B0000000A2457100058::-45.5:CNET
T 2014/01/03 09:01:06.924711 192.168.2.102:2323 -> 192.168.2.106:50996 [AP]  A0FCC861022262B0000000A245710005839..                                                                                                 


Zwischen Empfang auf der Netzwerkschicht und Dispatch liegen ca. 2-3ms. Also kann man die gemessenen Latenzen durchaus als valide betrachten.

Die wenigen Lichtblicke mit bis zu unter 30ms Latenz lassen mich hoffen, dass das Problem auf der Firmware Seite gelöst werden könnte. Vielleicht kann sich da ja Busware (tostmann?) dazu äußern.

rudolfkoenig

ZitatVielleicht kann sich da ja Busware (tostmann?) dazu äußern.

Ich meine aber, dass er sich fuer das Firmware nicht zustaendig fuehlt.
Wie ich das schon geschrieben habe, es fehlt an einem CUNO Maintainer.

rene

Zuständigkeiten und Gewährleistungen hin und her, hoffe ich einfach darauf, dass tostmann als letzter und häufigster Committer des Codes (Maintainer?) zumindest ohne großen Zeitaufwand einschätzen können sollte, woher das Delay kommt, und ob es sich beheben lässt.

Am Ende baue ich darauf, dass der Anbieter der Hardware ähnlich hohes Engagement in die Maintenance investiert, wie wir Kunden ins Testen. Und solange CUNO2 nicht zum Auslaufmodell wird, dürfte ein Interesse an der Verbesserung der Firmware seitens busware/tostmann durchaus bestehen. Automobilhersteller forschen ja auch an der Verbesserung von Treibstoffen, obwohl sie dafür eigentlich nicht zuständig sind. ;)

Ich schreib ihn aber auch gern als Käufer des CUNO2 nochmal direkt an, sollte das notwendig sein. :)

PS: was ihr Jungs hier an Zeit für Support und Produktpflege investiert ist beeindruckend und sicher nicht selbstverständlich.

tostmann

Der CUNO ist ca. 5 Jahre alt und kein Hochleistungsrechner. Der 8bit ATMEL bekommt es gerade so hin auch das Netzwerk ausreichend schnell zu bedienen. Zeitkritische ACK oä sollte man nicht erst über das Netzwerk schicken sondern, so wie bei MAX!, direkt im CUNO behandeln.
Leider kenn' ich mich NULL mit HM aus, kann daher auch keinen Weg zur Verbesserung aufzeigen. Clever ist in o.g. Zusammenhang besser einen Raspberry mit CUL/COC zu nutzen - das eröffnet weitere zusätzliche Möglichkeiten und krankt bestimmt nicht an Geschwindigkeit.

rene

Vielen Dank für die Rückmeldung.

Ich übersetz das mal in "Firmware-seitig eher schwierig zu lösen, ohne komplette Teile der Logik aus FHEM in die Firmware zu verlagern".

Das gibt zumindest schonmal Gewissheit auf schlechte Chancen. ;)

So gesehen wäre es aber glaube ich angebracht, auf der Produktseite einen kleinen Hinweis zu den Nutzungseinschränkungen mit HomeMatic zu hinterlegen. Ich für meinen Teil werde ihn wohl eher dann künftig im USB Mode betreiben, da ich den IR_RX brauche und mir keine andere Komplettlösung bekannt ist. Ausserdem ist das Geld halt nun mal ausgegeben und irgendwie werde ich ihn schon auch mit USB Kabel in Sichtweite zu den IR Komponenten bringen. ;)

Danke nochmal tostmann.