Neues Modul: 98_FREEZEMON Freezes monitoren und Verursacher identifizieren

FhemPiUser · 30 August 2022, 21:01:19

cannot fork ist leider erneut aufgetreten, die zwei disabled devices können also nicht die Ursache gewesen sein.

Man sieht, dass innerhalb von 2 Tagen die RAM-Nutzung ganz langsam ansteigt. Ich denke es muss also wohl irgendwo ein kleines Speicherleck geben.

Um dem auf die Spur zu kommen habe ich jetzt im freezemon das attr fm_logFile gesetzt und es wurden zwei Logfiles geschrieben zum Zeitpunkt des "cannot fork". Die Meldung kommt direkt nach dem PRESENCE-Modul (s.u.). Ist das ein Hinweis, dass es vom PRESENCE-Modul kommen könnte?

Code Auswählen

2022.08.30 20:45:04.646 4: PRESENCE (presence_raspcam2) - rescheduling next check in 10 seconds
2022.08.30 20:45:04.703 5: PRESENCE (presence_raspcam) - stopping timer
2022.08.30 20:45:04.704 5: PRESENCE (presence_raspcam) - starting blocking call for mode lan-ping
2022.08.30 20:45:04.734 1: Cannot fork: Cannot allocate memory
2022.08.30 20:45:04.735 1: Cannot fork: Cannot allocate memory

Der Blocking Call des PRESENCE-Moduls könnte aber auch nur das "Fass" zum Überlaufen gebracht haben (kein Speicher mehr) und das eigentliche Speicherleck ist in einem andern Modul. Nur wie bekomme ich den eigentlichen Verursacher heraus?

KölnSolar · 31 August 2022, 07:42:28

PRESENCE taucht in letzter Zeit gerne mal als "Störenfried" auf.

Ansonsten kann ich Deiner Analyse nur zustimmen ohne eine Idee zu haben, wie Du dem Verursacher auf die Spur kommen kannst. Siehst Du im System(sudo ps -e) "verstorbene" FHEM-Prozesse ?

Maui · 31 August 2022, 07:56:37

Ich würde das ganze zu Fuß analysieren.
Der RAM wird sicherlich halbwegs stetig anwachsen, ich würde ihn loggen und im Plot angucken.
Dann hast du grob ein Gefühl für die Steigung und kannst nach und nach einzelne devices disablen bis der Anstieg aufhört. Also immer nur 1 device pro 3 Std oder so disablen. Dabei würde ich mit den Exoten anfangen, also doif, at etc würde ich erst einmal ignorieren und eher sowas wie alexa, telegram, httpmod am anfang ins visier nehmen.

FhemPiUser · 31 August 2022, 08:08:18

Ja, die RAM Nutzung zeichne ich auf und es ist ein ganz langsamer Anstieg zu sehen über mehrere Tage (s. Bilder).

Wie erkenne ich denn verstorbene Prozesse? Sudo ps -e zeigt alle Prozesse. Ein Top sortiert nach Memory-Bedarf (Shift-M) sieht für mich nicht nach einem verstorbenen Prozess aus (siehe Screenshot).

Ich überlege schon auf den Raspi 4 mit 8 GB RAM umzusteigen. Vermutlich ist mein Raspi 3 mit 1 GB auch mit meiner fhem Installation langsam überfordert. HAbe >1200 devices.

KölnSolar · 31 August 2022, 08:19:13

Du siehst ja die pid, aus der auf das Alter schließen lässt.

Dein top zeigt meines Erachtens uralte Prozesse. Mit kill bekommst Du sie weg. Wie Du dann das forking monitoren kannst weiß ich aber auch nicht. Vielleicht mal einen neuen Thread aufmachen, dass die Spezies aufmerksam werden ?

ZitatIch überlege schon auf den Raspi 4 mit 8 GB RAM umzusteigen. Vermutlich ist mein Raspi 3 mit 1 GB auch mit meiner fhem Installation langsam überfordert. HAbe >1200 devices.

Ich denke eher, dass es ein anderes Problem ist.

Maui · 31 August 2022, 08:24:02

Ich hätte ehrlich gesagt mit einem steileren Anstieg gerechnet. Sieht fast so aus, als wäre RAM gar nicht dein eigentliches Problem.
Guck doch mal wie viele fhem prozesse du hast, zb so

Code Auswählen

sudo ps aux | grep fhem.pl | wc -l

Ach und einen kannst da abziehen beim Ergebnis, weil der grep sich selbst findet.

Ich denke auch nicht dass ein neuer Pi dein Problem wirklich lösen wird, der wird höchstens länger durchhalten

rudolfkoenig · 31 August 2022, 10:54:30

Es gab hier im Forum ein Bericht, dass das FREEZEMON Modul selbst zu Speicherverlust fuehrt, weiss aber nicht mehr wo. Das Modul bietet mW keine Moeglichkeit, die Ursache des Speicherlochs festzustellen, ich weiss nach etlichen Versuchen auch nicht, wie man das Suchen nach der Ursache benutzerfreundlich gestalten koennte.

FHEM verwendet fork fuer parallelisiertes Rechnen (z.Bsp. bei der Erstellung der SVGs), und zum Vermeiden der Blockierung (z.Bsp. per BlockingCall). Der urspruengliche fork() Aufruf hat den kompletten Speicherbereich des Aufrufers dupliziert. In modernen Systemen ist das deutlich komplizierter, es bedeutet aber weiterhin das Reservieren von zusaetzlichen RAM, dessen Groesse vom Aufrufer abhaengt.
D.h. je groesser FHEM vor dem fork() ist, desto eher gibt es Probleme beim fork().

Da der Speicher wahrscheinlich nur reserviert, aber nicht verwendet wird, koennte das Einrichten eines (groesseren) swap Bereiches, oder das Aendern des Reservierungsfaktors (Stichwort overcommit, eher was fuer Experten) helfen. Das ist keine Loesung, nur ein Workaround, der das Unvermeidbare verschiebt.
Genauso wie der Kauf eines Rechners mit mehr RAM.

FhemPiUser · 31 August 2022, 17:40:34

Eine Frage: Ich habe sehr viele presence / lan-ping devices. Macht es Sinn bzw. ist es möglich, die BlockingCalls von solchen devices wie presence irgendwie möglichst gleichmäßig zeitlich zu verteilen, damit nicht alle gleichzeitig forken / Speicher anfragen?

Man könnte es manuell über ein alignTime attr machen, wäre aber aufwändig und ist auch glaube ich nicht vorgesehen im presence modul. Oder kann das fhem irgendwie automatisch?

Maui · 31 August 2022, 18:15:06

Brauchst du denn wirklich so viele pings und reicht es nicht wenn sie seltener laufen?
Bzw. Bist du nicht mit nmap oder Zugriff auf fritz box besser dran?

rudolfkoenig · 31 August 2022, 18:41:10

ZitatEine Frage: Ich habe sehr viele presence / lan-ping devices. Macht es Sinn bzw. ist es möglich, die BlockingCalls von solchen devices wie presence irgendwie möglichst gleichmäßig zeitlich zu verteilen, damit nicht alle gleichzeitig forken / Speicher anfragen?

Es gibt ein global Attribut blockingCallMax (Voreinstellung 32), was die Anzahl dieser Prozesse begrenzt.
Ueberzaehlige Aufrufe werden in eine Warteschlange gesteckt.
Beobachten kann man die Schlange mit dem FHEM Befehl blockinginfo, er ist nur vorhanden, wenn BlockingCall schon verwendet wurde.

Benni · 01 September 2022, 21:26:57

Zitat von: FhemPiUser am 31 August 2022, 17:40:34
Eine Frage: Ich habe sehr viele presence / lan-ping devices.

Es gibt da eine "inoffizielle" Variante: https://forum.fhem.de/index.php?topic=117007.0
die genau das besser macht!

Die habe ich quasi seit sie existiert, erfolgreich mit vielen lan-ping im Einsatz.

gb#

FhemPiUser · 04 September 2022, 21:01:17

Ich habe jetzt durch Ausprobieren bzw. disablen der zuletzt angelegten devices folgenden Zusammenhang zwischen steigender RAM-Nutzung / cannot-fork-Fehlermeldungen erkannt:

Ich habe 4-5 Tage 2 modbusattr relay devices disabled laufen lassen -> Keine steigende RAM-Nutzung. Gestern habe ich dann die beiden modbusattr relay devices wieder enabled -> heute steigende RAM-Nutzung und cannot fork. Sonst habe ich nichts verändert. Ich habe noch 2 weitere mobusattr devices, die nicht im relay-Modus laufen. Die liefen die ganze Zeit durch ohne steigend RAM-Nutzung.

Das klingt für mich danach, dass die beiden modbusattr relay devices irgendetwas mit dem Speicherleck/steigenen RAM-Bedarf zu tun haben. Die beiden modbusattr relay devices werden von evcc (https://evcc.io/) genutzt, um über den relay per modbus mit 2 Sungrow SH10RT Wechselrichtern zu sprechen (die jeweils nur einen modbus client erlauben) und das funktioniert sonst auch gut. Ich bin absoluter Fan vom modbusattr device im relay modus und würde es gerne weiter verwenden. Momentan muss ich leider fhem alle 2-3 Tage neu starten aufgrund des Speicherlecks. Den Modulentwiockler StefanStrobl habe ich bereits informiert.

Die modbusattr relay devices sind wie folgt definiert:

Code Auswählen


defmod SH10rt_1_relay ModbusAttr 11 relay 192.168.1.xx:1502 TCP to SH10rt_1
defmod SH10rt_2_relay ModbusAttr 11 relay 192.168.1.xx:1503 TCP to SH10rt_2

Die modbusattr devices sind wie folgt definiert:

Code Auswählen


defmod SH10rt_1 ModbusAttr 1 30 192.168.3.xxx:502 TCP
defmod SH10rt_2 ModbusAttr 1 30 192.168.3.xxx:502 TCP

Letztere haben allerdings jeweils sehr viele modbus Attribute (>1200 attr Zeilen). Ich könnte mir vorstellen, dass dadurch ein sehr kleines Speicherleck bei mir auffällt, was bei anderen mit wenigen modbus Attributen nicht auffällt.

Oder kann es daran liegen, dass einige requests vom Wechselrichter nicht beantwortet werden (ist leider eine schlechte modbus-Implementierung im Wechselrichter SH10RT) und dadurch states im relay "hängen" bleiben?

Die modbusattr relay devices haben außerdem folgenden stacktrace als Reading:

Code Auswählen


TcpServer_Close:1712 Modbus::DoClose:903 Modbus::SetLDInactive:881 Modbus::AttrLDFn:3955 CallFn:3178 CommandAttr:1274 AnalyzeCommand:2806 FW_fC:984 FW_answerCall:609 FW_Read:3955 CallFn:782

Hat noch jemand eine Idee oder kann ich noch irgendetwas tun, um der Ursache und der Lösung auf die Spur zu kommen?

P.S.: Danke Benni für den Tipp mit den presence-devices. Schaue ich mir mal an zur Optimierung, die presence devcies scheinen aber nichts mit meinem Speicherleck-Problem zu tun zu haben.

rudolfkoenig · 05 September 2022, 09:37:38

ZitatDie modbusattr relay devices haben außerdem folgenden stacktrace als Reading:

Hier wurde leider das Wesentliche an der Fehlermeldung weggelassen, das ist vmtl. eine Zeile mit WARNING davor.
Wir wissen jetzt wo das Problem ausgeloest wurde, aber nicht, was das Problem ist.

Zum Thema Speicherleck habe ich leider keine Idee.

FhemPiUser · 05 September 2022, 12:30:52

danke, ich warte mal auf den nächsten error, dann poste ich das ganze stacktrace nochmal.

Ich habe erstmal kurz mit verbose 5 beim modbusattr relay mitgeloggt - falls es hilft.
Da kommt öfter "read from TCP server connection got null -> closing" und "_UnDef is closing SH10rt_1_relay" nach dem send. Ich weiß nicht, ob das relevant ist...

Code Auswählen


022.09.05 12:24:54.222 5: SH10rt_1_relay: UpdateSetList: setList=reconnect:noArg saveAsModule createAttrsFromParseInfo inactive active
2022.09.05 12:24:54.223 5: SH10rt_1_relay: UpdateSetList: getList=
2022.09.05 12:24:55.431 4: Connection accepted from SH10rt_1_relay_192.168.x.x_48796
2022.09.05 12:24:55.432 4: SH10rt_1_relay: HandleServerConnection accepted new TCP connection as device SH10rt_1_relay_192.168.x.x_48796
2022.09.05 12:24:55.807 5: SH10rt_1_relay_192.168.x.x_48796: readFn buffer: 0988000000060b0413980002
2022.09.05 12:24:55.809 5: SH10rt_1_relay_192.168.x.x_48796: ParseFrameStart called from ReadFn
2022.09.05 12:24:55.810 4: SH10rt_1_relay_192.168.x.x_48796: ParseFrameStart (TCP, relay) extracted id 11, fCode 4, tid 2440, dlen 6 and potential data 13980002
2022.09.05 12:24:55.811 5: SH10rt_1_relay_192.168.x.x_48796: HandleRequest called from ReadFn
2022.09.05 12:24:55.812 5: SH10rt_1_relay_192.168.x.x_48796: ParseRequest called from HandleRequest
2022.09.05 12:24:55.813 4: SH10rt_1_relay_192.168.x.x_48796: HandleRequest, current frame / read buffer: 0988000000060b0413980002, id 11, fCode 4, tid 2440,
request: id 11 fc 4 i5016, len 2, tid 2440
2022.09.05 12:24:55.815 4: SH10rt_1_relay_192.168.x.x_48796: RelayRequest called from HandleRequest
2022.09.05 12:24:55.816 5: SH10rt_1_relay: GetRelayIO found SH10rt_1 as Modbus relay forward io device for SH10rt_1 with id 1
2022.09.05 12:24:55.817 4: SH10rt_1_relay_192.168.x.x_48796: RelayRequest via SH10rt_1, Proto TCP with id 1, current frame / read buffer: 0988000000060b0413980002, id 11, fCode 4, tid 2440,
request: id 11 fc 4 i5016, len 2, tid 2440, for relay device SH10rt_1_relay_192.168.x.x_48796
2022.09.05 12:24:55.827 4: SH10rt_1_relay_192.168.x.x_48796: HandleRequest Done, current frame / read buffer: 0988000000060b0413980002, id 11, fCode 4, tid 2440,
request: id 11 fc 4 i5016, len 2, tid 2440, for relay device SH10rt_1_relay_192.168.x.x_48796
2022.09.05 12:24:55.828 5: SH10rt_1_relay_192.168.x.x_48796: DropFrame called from ReadFn - drop 0988000000060b0413980002
2022.09.05 12:24:56.089 3: SH10rt_1_relay_192.168.x.x_48796: read from TCP server connection got null -> closing
2022.09.05 12:24:56.089 3: SH10rt_1_relay_192.168.x.x_48796: _UnDef is closing SH10rt_1_relay_192.168.x.x_48796
2022.09.05 12:24:56.090 5: SH10rt_1_relay_192.168.x.x_48796: Close called from UndefLDFn with noState and noDelete
2022.09.05 12:24:56.090 4: SH10rt_1_relay_192.168.x.x_48796: Close TCP server listening connection and delete hash
2022.09.05 12:24:56.270 5: SH10rt_1_relay_192.168.x.x_48796: Close is removing lastconn from parent device SH10rt_1_relay
2022.09.05 12:24:56.461 5: SH10rt_1_relay: ParseDataString called from HandleResponse with data hex 1d130000, type i, adr 5016
2022.09.05 12:24:56.461 5: SH10rt_1_relay: SplitDataString called from ParseDataString with data hex 1d130000, type i, adr 5016, valuesLen 2
2022.09.05 12:24:56.461 5: SH10rt_1_relay: SplitDataString has no information about handling i5016
2022.09.05 12:24:56.462 5: SH10rt_1_relay: SplitDataString has no information about handling i5017
2022.09.05 12:24:56.462 5: SH10rt_1_relay: CreateDataObjects called from ParseDataString with objList
2022.09.05 12:24:56.462 5: SH10rt_1_relay: CreateDataObjects sortedList
2022.09.05 12:24:56.463 5: SH10rt_1_relay: ParseDataString created 0 readings
2022.09.05 12:24:56.463 1: PERL WARNING: Use of uninitialized value in concatenation (.) or string at ./FHEM/98_Modbus.pm line 3067.
2022.09.05 12:24:56.464 1: PERL WARNING: Use of uninitialized value $proto in string eq at ./FHEM/98_Modbus.pm line 3694.
2022.09.05 12:24:56.464 1: PERL WARNING: Use of uninitialized value $proto in string eq at ./FHEM/98_Modbus.pm line 3698.
2022.09.05 12:24:56.464 1: PERL WARNING: Use of uninitialized value $proto in string eq at ./FHEM/98_Modbus.pm line 3703.
2022.09.05 12:24:56.464 1: PERL WARNING: Use of uninitialized value $proto in concatenation (.) or string at ./FHEM/98_Modbus.pm line 3709.
2022.09.05 12:24:56.592 4: Connection accepted from SH10rt_1_relay_192.168.x.x_48798
2022.09.05 12:24:56.592 4: SH10rt_1_relay: HandleServerConnection accepted new TCP connection as device SH10rt_1_relay_192.168.x.x_48798
2022.09.05 12:24:56.751 5: SH10rt_1_relay_192.168.x.x_48798: readFn buffer: 0989000000060b0413980002
2022.09.05 12:24:56.752 5: SH10rt_1_relay_192.168.x.x_48798: ParseFrameStart called from ReadFn
2022.09.05 12:24:56.752 4: SH10rt_1_relay_192.168.x.x_48798: ParseFrameStart (TCP, relay) extracted id 11, fCode 4, tid 2441, dlen 6 and potential data 13980002
2022.09.05 12:24:56.752 5: SH10rt_1_relay_192.168.x.x_48798: HandleRequest called from ReadFn
2022.09.05 12:24:56.753 5: SH10rt_1_relay_192.168.x.x_48798: ParseRequest called from HandleRequest
2022.09.05 12:24:56.753 4: SH10rt_1_relay_192.168.x.x_48798: HandleRequest, current frame / read buffer: 0989000000060b0413980002, id 11, fCode 4, tid 2441,
request: id 11 fc 4 i5016, len 2, tid 2441
2022.09.05 12:24:56.753 4: SH10rt_1_relay_192.168.x.x_48798: RelayRequest called from HandleRequest
2022.09.05 12:24:56.754 5: SH10rt_1_relay: GetRelayIO found SH10rt_1 as Modbus relay forward io device for SH10rt_1 with id 1
2022.09.05 12:24:56.754 4: SH10rt_1_relay_192.168.x.x_48798: RelayRequest via SH10rt_1, Proto TCP with id 1, current frame / read buffer: 0989000000060b0413980002, id 11, fCode 4, tid 2441,
request: id 11 fc 4 i5016, len 2, tid 2441, for relay device SH10rt_1_relay_192.168.x.x_48798
2022.09.05 12:24:56.760 4: SH10rt_1_relay_192.168.x.x_48798: HandleRequest Done, current frame / read buffer: 0989000000060b0413980002, id 11, fCode 4, tid 2441,
request: id 11 fc 4 i5016, len 2, tid 2441, for relay device SH10rt_1_relay_192.168.x.x_48798
2022.09.05 12:24:56.760 5: SH10rt_1_relay_192.168.x.x_48798: DropFrame called from ReadFn - drop 0989000000060b0413980002
2022.09.05 12:24:56.993 5: SH10rt_1_relay: ParseDataString called from HandleResponse with data hex 1d140000, type i, adr 5016
2022.09.05 12:24:56.994 5: SH10rt_1_relay: SplitDataString called from ParseDataString with data hex 1d140000, type i, adr 5016, valuesLen 2
2022.09.05 12:24:56.994 5: SH10rt_1_relay: SplitDataString has no information about handling i5016
2022.09.05 12:24:56.994 5: SH10rt_1_relay: SplitDataString has no information about handling i5017
2022.09.05 12:24:56.995 5: SH10rt_1_relay: CreateDataObjects called from ParseDataString with objList
2022.09.05 12:24:56.995 5: SH10rt_1_relay: CreateDataObjects sortedList
2022.09.05 12:24:56.995 5: SH10rt_1_relay: ParseDataString created 0 readings
2022.09.05 12:24:56.996 5: SH10rt_1_relay_192.168.x.x_48798: Send called from RelayResponse
2022.09.05 12:24:56.996 4: SH10rt_1_relay_192.168.x.x_48798: Send 0989000000070b04041d140000
2022.09.05 12:24:57.089 5: SH10rt_1_relay_192.168.x.x_48798: readFn buffer: 098a000000060b0432dd0001
2022.09.05 12:24:57.090 5: SH10rt_1_relay_192.168.x.x_48798: ParseFrameStart called from ReadFn protocol TCP expecting id 11
2022.09.05 12:24:57.090 4: SH10rt_1_relay_192.168.x.x_48798: ParseFrameStart (TCP, relay) extracted id 11, fCode 4, tid 2442, dlen 6 and potential data 32dd0001
2022.09.05 12:24:57.090 5: SH10rt_1_relay_192.168.x.x_48798: HandleRequest called from ReadFn
2022.09.05 12:24:57.090 5: SH10rt_1_relay_192.168.x.x_48798: ParseRequest called from HandleRequest
2022.09.05 12:24:57.091 4: SH10rt_1_relay_192.168.x.x_48798: HandleRequest, current frame / read buffer: 098a000000060b0432dd0001, id 11, fCode 4, tid 2442,
request: id 11 fc 4 i13021, len 1, tid 2442
2022.09.05 12:24:57.091 4: SH10rt_1_relay_192.168.x.x_48798: RelayRequest called from HandleRequest
2022.09.05 12:24:57.091 5: SH10rt_1_relay: GetRelayIO found SH10rt_1 as Modbus relay forward io device for SH10rt_1 with id 1
2022.09.05 12:24:57.092 4: SH10rt_1_relay_192.168.x.x_48798: RelayRequest via SH10rt_1, Proto TCP with id 1, current frame / read buffer: 098a000000060b0432dd0001, id 11, fCode 4, tid 2442,
request: id 11 fc 4 i13021, len 1, tid 2442, for relay device SH10rt_1_relay_192.168.x.x_48798
2022.09.05 12:24:57.097 4: SH10rt_1_relay_192.168.x.x_48798: HandleRequest Done, current frame / read buffer: 098a000000060b0432dd0001, id 11, fCode 4, tid 2442,
request: id 11 fc 4 i13021, len 1, tid 2442, for relay device SH10rt_1_relay_192.168.x.x_48798
2022.09.05 12:24:57.098 5: SH10rt_1_relay_192.168.x.x_48798: DropFrame called from ReadFn - drop 098a000000060b0432dd0001
2022.09.05 12:24:57.102 5: SH10rt_1_relay: ParseDataString called from HandleResponse with data hex 07e2, type i, adr 13021
2022.09.05 12:24:57.102 5: SH10rt_1_relay: SplitDataString called from ParseDataString with data hex 07e2, type i, adr 13021, valuesLen 1
2022.09.05 12:24:57.103 5: SH10rt_1_relay: SplitDataString has no information about handling i13021
2022.09.05 12:24:57.103 5: SH10rt_1_relay: CreateDataObjects called from ParseDataString with objList
2022.09.05 12:24:57.103 5: SH10rt_1_relay: CreateDataObjects sortedList
2022.09.05 12:24:57.103 5: SH10rt_1_relay: ParseDataString created 0 readings
2022.09.05 12:24:57.104 5: SH10rt_1_relay_192.168.x.x_48798: Send called from RelayResponse
2022.09.05 12:24:57.104 4: SH10rt_1_relay_192.168.x.x_48798: Send 098a000000050b040207e2
2022.09.05 12:24:57.110 5: SH10rt_1_relay_192.168.x.x_48798: readFn buffer: 098b000000060b0432c80001
2022.09.05 12:24:57.110 5: SH10rt_1_relay_192.168.x.x_48798: ParseFrameStart called from ReadFn protocol TCP expecting id 11
2022.09.05 12:24:57.110 4: SH10rt_1_relay_192.168.x.x_48798: ParseFrameStart (TCP, relay) extracted id 11, fCode 4, tid 2443, dlen 6 and potential data 32c80001
2022.09.05 12:24:57.111 5: SH10rt_1_relay_192.168.x.x_48798: HandleRequest called from ReadFn
2022.09.05 12:24:57.111 5: SH10rt_1_relay_192.168.x.x_48798: ParseRequest called from HandleRequest
2022.09.05 12:24:57.111 4: SH10rt_1_relay_192.168.x.x_48798: HandleRequest, current frame / read buffer: 098b000000060b0432c80001, id 11, fCode 4, tid 2443,
request: id 11 fc 4 i13000, len 1, tid 2443
2022.09.05 12:24:57.112 4: SH10rt_1_relay_192.168.x.x_48798: RelayRequest called from HandleRequest
2022.09.05 12:24:57.112 5: SH10rt_1_relay: GetRelayIO found SH10rt_1 as Modbus relay forward io device for SH10rt_1 with id 1
2022.09.05 12:24:57.112 4: SH10rt_1_relay_192.168.x.x_48798: RelayRequest via SH10rt_1, Proto TCP with id 1, current frame / read buffer: 098b000000060b0432c80001, id 11, fCode 4, tid 2443,
request: id 11 fc 4 i13000, len 1, tid 2443, for relay device SH10rt_1_relay_192.168.x.x_48798
2022.09.05 12:24:57.205 4: SH10rt_1_relay_192.168.x.x_48798: HandleRequest Done, current frame / read buffer: 098b000000060b0432c80001, id 11, fCode 4, tid 2443,
request: id 11 fc 4 i13000, len 1, tid 2443, for relay device SH10rt_1_relay_192.168.x.x_48798
2022.09.05 12:24:57.206 5: SH10rt_1_relay_192.168.x.x_48798: DropFrame called from ReadFn - drop 098b000000060b0432c80001
2022.09.05 12:24:57.211 5: SH10rt_1_relay: ParseDataString called from HandleResponse with data hex 0000, type i, adr 13000
2022.09.05 12:24:57.211 5: SH10rt_1_relay: SplitDataString called from ParseDataString with data hex 0000, type i, adr 13000, valuesLen 1
2022.09.05 12:24:57.211 5: SH10rt_1_relay: SplitDataString has no information about handling i13000
2022.09.05 12:24:57.211 5: SH10rt_1_relay: CreateDataObjects called from ParseDataString with objList
2022.09.05 12:24:57.212 5: SH10rt_1_relay: CreateDataObjects sortedList
2022.09.05 12:24:57.212 5: SH10rt_1_relay: ParseDataString created 0 readings
2022.09.05 12:24:57.213 5: SH10rt_1_relay_192.168.x.x_48798: Send called from RelayResponse
2022.09.05 12:24:57.213 4: SH10rt_1_relay_192.168.x.x_48798: Send 098b000000050b04020000
2022.09.05 12:24:57.218 5: SH10rt_1_relay_192.168.x.x_48798: readFn buffer: 098c000000060b0432c80001
2022.09.05 12:24:57.219 5: SH10rt_1_relay_192.168.x.x_48798: ParseFrameStart called from ReadFn protocol TCP expecting id 11
2022.09.05 12:24:57.219 4: SH10rt_1_relay_192.168.x.x_48798: ParseFrameStart (TCP, relay) extracted id 11, fCode 4, tid 2444, dlen 6 and potential data 32c80001
2022.09.05 12:24:57.219 5: SH10rt_1_relay_192.168.x.x_48798: HandleRequest called from ReadFn
2022.09.05 12:24:57.220 5: SH10rt_1_relay_192.168.x.x_48798: ParseRequest called from HandleRequest
2022.09.05 12:24:57.220 4: SH10rt_1_relay_192.168.x.x_48798: HandleRequest, current frame / read buffer: 098c000000060b0432c80001, id 11, fCode 4, tid 2444,
request: id 11 fc 4 i13000, len 1, tid 2444
2022.09.05 12:24:57.220 4: SH10rt_1_relay_192.168.x.x_48798: RelayRequest called from HandleRequest
2022.09.05 12:24:57.221 5: SH10rt_1_relay: GetRelayIO found SH10rt_1 as Modbus relay forward io device for SH10rt_1 with id 1
2022.09.05 12:24:57.221 4: SH10rt_1_relay_192.168.x.x_48798: RelayRequest via SH10rt_1, Proto TCP with id 1, current frame / read buffer: 098c000000060b0432c80001, id 11, fCode 4, tid 2444,
request: id 11 fc 4 i13000, len 1, tid 2444, for relay device SH10rt_1_relay_192.168.x.x_48798
2022.09.05 12:24:57.313 4: SH10rt_1_relay_192.168.x.x_48798: HandleRequest Done, current frame / read buffer: 098c000000060b0432c80001, id 11, fCode 4, tid 2444,
request: id 11 fc 4 i13000, len 1, tid 2444, for relay device SH10rt_1_relay_192.168.x.x_48798
2022.09.05 12:24:57.313 5: SH10rt_1_relay_192.168.x.x_48798: DropFrame called from ReadFn - drop 098c000000060b0432c80001
2022.09.05 12:24:57.318 5: SH10rt_1_relay: ParseDataString called from HandleResponse with data hex 0000, type i, adr 13000
2022.09.05 12:24:57.318 5: SH10rt_1_relay: SplitDataString called from ParseDataString with data hex 0000, type i, adr 13000, valuesLen 1
2022.09.05 12:24:57.318 5: SH10rt_1_relay: SplitDataString has no information about handling i13000
2022.09.05 12:24:57.319 5: SH10rt_1_relay: CreateDataObjects called from ParseDataString with objList
2022.09.05 12:24:57.319 5: SH10rt_1_relay: CreateDataObjects sortedList
2022.09.05 12:24:57.319 5: SH10rt_1_relay: ParseDataString created 0 readings
2022.09.05 12:24:57.320 5: SH10rt_1_relay_192.168.x.x_48798: Send called from RelayResponse
2022.09.05 12:24:57.320 4: SH10rt_1_relay_192.168.x.x_48798: Send 098c000000050b04020000
2022.09.05 12:24:57.326 5: SH10rt_1_relay_192.168.x.x_48798: readFn buffer: 098d000000060b0432d10002
2022.09.05 12:24:57.326 5: SH10rt_1_relay_192.168.x.x_48798: ParseFrameStart called from ReadFn protocol TCP expecting id 11
2022.09.05 12:24:57.326 4: SH10rt_1_relay_192.168.x.x_48798: ParseFrameStart (TCP, relay) extracted id 11, fCode 4, tid 2445, dlen 6 and potential data 32d10002
2022.09.05 12:24:57.327 5: SH10rt_1_relay_192.168.x.x_48798: HandleRequest called from ReadFn
2022.09.05 12:24:57.327 5: SH10rt_1_relay_192.168.x.x_48798: ParseRequest called from HandleRequest
2022.09.05 12:24:57.327 4: SH10rt_1_relay_192.168.x.x_48798: HandleRequest, current frame / read buffer: 098d000000060b0432d10002, id 11, fCode 4, tid 2445,
request: id 11 fc 4 i13009, len 2, tid 2445
2022.09.05 12:24:57.328 4: SH10rt_1_relay_192.168.x.x_48798: RelayRequest called from HandleRequest
2022.09.05 12:24:57.328 5: SH10rt_1_relay: GetRelayIO found SH10rt_1 as Modbus relay forward io device for SH10rt_1 with id 1
2022.09.05 12:24:57.328 4: SH10rt_1_relay_192.168.x.x_48798: RelayRequest via SH10rt_1, Proto TCP with id 1, current frame / read buffer: 098d000000060b0432d10002, id 11, fCode 4, tid 2445,
request: id 11 fc 4 i13009, len 2, tid 2445, for relay device SH10rt_1_relay_192.168.x.x_48798
2022.09.05 12:24:57.420 4: SH10rt_1_relay_192.168.x.x_48798: HandleRequest Done, current frame / read buffer: 098d000000060b0432d10002, id 11, fCode 4, tid 2445,
request: id 11 fc 4 i13009, len 2, tid 2445, for relay device SH10rt_1_relay_192.168.x.x_48798
2022.09.05 12:24:57.420 5: SH10rt_1_relay_192.168.x.x_48798: DropFrame called from ReadFn - drop 098d000000060b0432d10002
2022.09.05 12:24:57.440 5: SH10rt_1_relay: ParseDataString called from HandleResponse with data hex 02470000, type i, adr 13009
2022.09.05 12:24:57.441 5: SH10rt_1_relay: SplitDataString called from ParseDataString with data hex 02470000, type i, adr 13009, valuesLen 2
2022.09.05 12:24:57.441 5: SH10rt_1_relay: SplitDataString has no information about handling i13009
2022.09.05 12:24:57.441 5: SH10rt_1_relay: SplitDataString has no information about handling i13010
2022.09.05 12:24:57.442 5: SH10rt_1_relay: CreateDataObjects called from ParseDataString with objList
2022.09.05 12:24:57.442 5: SH10rt_1_relay: CreateDataObjects sortedList
2022.09.05 12:24:57.442 5: SH10rt_1_relay: ParseDataString created 0 readings
2022.09.05 12:24:57.443 5: SH10rt_1_relay_192.168.x.x_48798: Send called from RelayResponse
2022.09.05 12:24:57.443 4: SH10rt_1_relay_192.168.x.x_48798: Send 098d000000070b040402470000
2022.09.05 12:24:57.449 5: SH10rt_1_relay_192.168.x.x_48798: readFn buffer: 098e000000060b0432de0001
2022.09.05 12:24:57.449 5: SH10rt_1_relay_192.168.x.x_48798: ParseFrameStart called from ReadFn protocol TCP expecting id 11
2022.09.05 12:24:57.449 4: SH10rt_1_relay_192.168.x.x_48798: ParseFrameStart (TCP, relay) extracted id 11, fCode 4, tid 2446, dlen 6 and potential data 32de0001
2022.09.05 12:24:57.450 5: SH10rt_1_relay_192.168.x.x_48798: HandleRequest called from ReadFn
2022.09.05 12:24:57.450 5: SH10rt_1_relay_192.168.x.x_48798: ParseRequest called from HandleRequest
2022.09.05 12:24:57.450 4: SH10rt_1_relay_192.168.x.x_48798: HandleRequest, current frame / read buffer: 098e000000060b0432de0001, id 11, fCode 4, tid 2446,
request: id 11 fc 4 i13022, len 1, tid 2446
2022.09.05 12:24:57.451 4: SH10rt_1_relay_192.168.x.x_48798: RelayRequest called from HandleRequest
2022.09.05 12:24:57.451 5: SH10rt_1_relay: GetRelayIO found SH10rt_1 as Modbus relay forward io device for SH10rt_1 with id 1
2022.09.05 12:24:57.451 4: SH10rt_1_relay_192.168.x.x_48798: RelayRequest via SH10rt_1, Proto TCP with id 1, current frame / read buffer: 098e000000060b0432de0001, id 11, fCode 4, tid 2446,
request: id 11 fc 4 i13022, len 1, tid 2446, for relay device SH10rt_1_relay_192.168.x.x_48798
2022.09.05 12:24:57.528 4: SH10rt_1_relay_192.168.x.x_48798: HandleRequest Done, current frame / read buffer: 098e000000060b0432de0001, id 11, fCode 4, tid 2446,
request: id 11 fc 4 i13022, len 1, tid 2446, for relay device SH10rt_1_relay_192.168.x.x_48798
2022.09.05 12:24:57.529 5: SH10rt_1_relay_192.168.x.x_48798: DropFrame called from ReadFn - drop 098e000000060b0432de0001
2022.09.05 12:24:57.535 5: SH10rt_1_relay: ParseDataString called from HandleResponse with data hex 0348, type i, adr 13022
2022.09.05 12:24:57.535 5: SH10rt_1_relay: SplitDataString called from ParseDataString with data hex 0348, type i, adr 13022, valuesLen 1
2022.09.05 12:24:57.535 5: SH10rt_1_relay: SplitDataString has no information about handling i13022
2022.09.05 12:24:57.535 5: SH10rt_1_relay: CreateDataObjects called from ParseDataString with objList
2022.09.05 12:24:57.536 5: SH10rt_1_relay: CreateDataObjects sortedList
2022.09.05 12:24:57.536 5: SH10rt_1_relay: ParseDataString created 0 readings
2022.09.05 12:24:57.537 5: SH10rt_1_relay_192.168.x.x_48798: Send called from RelayResponse
2022.09.05 12:24:57.537 4: SH10rt_1_relay_192.168.x.x_48798: Send 098e000000050b04020348
2022.09.05 12:25:02.455 3: SH10rt_1_relay_192.168.x.x_48798: read from TCP server connection got null -> closing
2022.09.05 12:25:02.456 3: SH10rt_1_relay_192.168.x.x_48798: _UnDef is closing SH10rt_1_relay_192.168.x.x_48798
2022.09.05 12:25:02.456 5: SH10rt_1_relay_192.168.x.x_48798: Close called from UndefLDFn with noState and noDelete
2022.09.05 12:25:02.456 4: SH10rt_1_relay_192.168.x.x_48798: Close TCP server listening connection and delete hash
2022.09.05 12:25:02.625 5: SH10rt_1_relay_192.168.x.x_48798: Close is removing lastconn from parent device SH10rt_1_relay
2022.09.05 12:25:05.029 4: Connection accepted from SH10rt_1_relay_192.168.x.x_48862
2022.09.05 12:25:05.029 4: SH10rt_1_relay: HandleServerConnection accepted new TCP connection as device SH10rt_1_relay_192.168.x.x_48862
2022.09.05 12:25:05.104 5: SH10rt_1_relay_192.168.x.x_48862: readFn buffer: 098f000000060b0413980002
2022.09.05 12:25:05.104 5: SH10rt_1_relay_192.168.x.x_48862: ParseFrameStart called from ReadFn
2022.09.05 12:25:05.105 4: SH10rt_1_relay_192.168.x.x_48862: ParseFrameStart (TCP, relay) extracted id 11, fCode 4, tid 2447, dlen 6 and potential data 13980002
2022.09.05 12:25:05.105 5: SH10rt_1_relay_192.168.x.x_48862: HandleRequest called from ReadFn
2022.09.05 12:25:05.105 5: SH10rt_1_relay_192.168.x.x_48862: ParseRequest called from HandleRequest
2022.09.05 12:25:05.106 4: SH10rt_1_relay_192.168.x.x_48862: HandleRequest, current frame / read buffer: 098f000000060b0413980002, id 11, fCode 4, tid 2447,
request: id 11 fc 4 i5016, len 2, tid 2447
2022.09.05 12:25:05.106 4: SH10rt_1_relay_192.168.x.x_48862: RelayRequest called from HandleRequest
2022.09.05 12:25:05.107 5: SH10rt_1_relay: GetRelayIO found SH10rt_1 as Modbus relay forward io device for SH10rt_1 with id 1
2022.09.05 12:25:05.107 5: SH10rt_1_relay: CreateResponse called from RelayRequest ErrCode=6
2022.09.05 12:25:05.108 5: SH10rt_1_relay: CreateResponse calls PackFrame to prepare response pdu
2022.09.05 12:25:05.108 5: SH10rt_1_relay_192.168.x.x_48862: PackResponse called from CreateResponse
2022.09.05 12:25:05.115 4: SH10rt_1_relay: CreateResponse sends response: id 11, fc 132, error code 6, i5016, len 2, tid 2447, device SH10rt_1_relay (TCP), pdu 8406, V 4.4.04 - 17.7.2021
2022.09.05 12:25:05.116 5: SH10rt_1_relay_192.168.x.x_48862: Send called from CreateResponse
2022.09.05 12:25:05.116 4: SH10rt_1_relay_192.168.x.x_48862: Send 098f000000030b8406
2022.09.05 12:25:05.117 4: SH10rt_1_relay_192.168.x.x_48862: HandleRequest Done, error: relay forward path busy, current frame / read buffer: 098f000000060b0413980002, id 11, fCode 4, tid 2447,
request: id 11 fc 4 i5016, len 2, tid 2447, for relay device SH10rt_1_relay_192.168.x.x_48862,
response: id 11, fc 132, error code 6, i5016, len 2, tid 2447, error: relay forward path busy
2022.09.05 12:25:05.117 5: SH10rt_1_relay_192.168.x.x_48862: DropFrame called from ReadFn - drop 098f000000060b0413980002
2022.09.05 12:25:05.167 3: SH10rt_1_relay_192.168.x.x_48862: read from TCP server connection got null -> closing
2022.09.05 12:25:05.168 3: SH10rt_1_relay_192.168.x.x_48862: _UnDef is closing SH10rt_1_relay_192.168.x.x_48862
2022.09.05 12:25:05.168 5: SH10rt_1_relay_192.168.x.x_48862: Close called from UndefLDFn with noState and noDelete
2022.09.05 12:25:05.168 4: SH10rt_1_relay_192.168.x.x_48862: Close TCP server listening connection and delete hash
2022.09.05 12:25:05.350 5: SH10rt_1_relay_192.168.x.x_48862: Close is removing lastconn from parent device SH10rt_1_relay
2022.09.05 12:25:05.670 4: Connection accepted from SH10rt_1_relay_192.168.x.x_48864
2022.09.05 12:25:05.671 4: SH10rt_1_relay: HandleServerConnection accepted new TCP connection as device SH10rt_1_relay_192.168.x.x_48864
2022.09.05 12:25:05.865 5: SH10rt_1_relay_192.168.x.x_48864: readFn buffer: 0990000000060b0413980002
2022.09.05 12:25:05.866 5: SH10rt_1_relay_192.168.x.x_48864: ParseFrameStart called from ReadFn
2022.09.05 12:25:05.867 4: SH10rt_1_relay_192.168.x.x_48864: ParseFrameStart (TCP, relay) extracted id 11, fCode 4, tid 2448, dlen 6 and potential data 13980002
2022.09.05 12:25:05.868 5: SH10rt_1_relay_192.168.x.x_48864: HandleRequest called from ReadFn
2022.09.05 12:25:05.869 5: SH10rt_1_relay_192.168.x.x_48864: ParseRequest called from HandleRequest
2022.09.05 12:25:05.870 4: SH10rt_1_relay_192.168.x.x_48864: HandleRequest, current frame / read buffer: 0990000000060b0413980002, id 11, fCode 4, tid 2448,
request: id 11 fc 4 i5016, len 2, tid 2448
2022.09.05 12:25:05.871 4: SH10rt_1_relay_192.168.x.x_48864: RelayRequest called from HandleRequest
2022.09.05 12:25:05.872 5: SH10rt_1_relay: GetRelayIO found SH10rt_1 as Modbus relay forward io device for SH10rt_1 with id 1
2022.09.05 12:25:05.873 4: SH10rt_1_relay_192.168.x.x_48864: RelayRequest via SH10rt_1, Proto TCP with id 1, current frame / read buffer: 0990000000060b0413980002, id 11, fCode 4, tid 2448,
request: id 11 fc 4 i5016, len 2, tid 2448, for relay device SH10rt_1_relay_192.168.x.x_48864
2022.09.05 12:25:05.883 4: SH10rt_1_relay_192.168.x.x_48864: HandleRequest Done, current frame / read buffer: 0990000000060b0413980002, id 11, fCode 4, tid 2448,
request: id 11 fc 4 i5016, len 2, tid 2448, for relay device SH10rt_1_relay_192.168.x.x_48864
2022.09.05 12:25:05.884 5: SH10rt_1_relay_192.168.x.x_48864: DropFrame called from ReadFn - drop 0990000000060b0413980002
2022.09.05 12:25:05.929 5: SH10rt_1_relay: ParseDataString called from HandleResponse with data hex 1d0c0000, type i, adr 5016
2022.09.05 12:25:05.929 5: SH10rt_1_relay: SplitDataString called from ParseDataString with data hex 1d0c0000, type i, adr 5016, valuesLen 2
2022.09.05 12:25:05.930 5: SH10rt_1_relay: SplitDataString has no information about handling i5016
2022.09.05 12:25:05.930 5: SH10rt_1_relay: SplitDataString has no information about handling i5017
2022.09.05 12:25:05.931 5: SH10rt_1_relay: CreateDataObjects called from ParseDataString with objList
2022.09.05 12:25:05.931 5: SH10rt_1_relay: CreateDataObjects sortedList
2022.09.05 12:25:05.931 5: SH10rt_1_relay: ParseDataString created 0 readings
2022.09.05 12:25:05.932 5: SH10rt_1_relay_192.168.x.x_48864: Send called from RelayResponse
2022.09.05 12:25:05.933 4: SH10rt_1_relay_192.168.x.x_48864: Send 0990000000070b04041d0c0000
2022.09.05 12:25:06.189 5: SH10rt_1_relay_192.168.x.x_48864: readFn buffer: 0991000000060b0432dd0001
2022.09.05 12:25:06.189 5: SH10rt_1_relay_192.168.x.x_48864: ParseFrameStart called from ReadFn protocol TCP expecting id 11
2022.09.05 12:25:06.190 4: SH10rt_1_relay_192.168.x.x_48864: ParseFrameStart (TCP, relay) extracted id 11, fCode 4, tid 2449, dlen 6 and potential data 32dd0001
2022.09.05 12:25:06.190 5: SH10rt_1_relay_192.168.x.x_48864: HandleRequest called from ReadFn
2022.09.05 12:25:06.191 5: SH10rt_1_relay_192.168.x.x_48864: ParseRequest called from HandleRequest
2022.09.05 12:25:06.191 4: SH10rt_1_relay_192.168.x.x_48864: HandleRequest, current frame / read buffer: 0991000000060b0432dd0001, id 11, fCode 4, tid 2449,
request: id 11 fc 4 i13021, len 1, tid 2449
2022.09.05 12:25:06.192 4: SH10rt_1_relay_192.168.x.x_48864: RelayRequest called from HandleRequest
2022.09.05 12:25:06.192 5: SH10rt_1_relay: GetRelayIO found SH10rt_1 as Modbus relay forward io device for SH10rt_1 with id 1
2022.09.05 12:25:06.193 4: SH10rt_1_relay_192.168.x.x_48864: RelayRequest via SH10rt_1, Proto TCP with id 1, current frame / read buffer: 0991000000060b0432dd0001, id 11, fCode 4, tid 2449,
request: id 11 fc 4 i13021, len 1, tid 2449, for relay device SH10rt_1_relay_192.168.x.x_48864
2022.09.05 12:25:06.199 4: SH10rt_1_relay_192.168.x.x_48864: HandleRequest Done, current frame / read buffer: 0991000000060b0432dd0001, id 11, fCode 4, tid 2449,
request: id 11 fc 4 i13021, len 1, tid 2449, for relay device SH10rt_1_relay_192.168.x.x_48864
2022.09.05 12:25:06.200 5: SH10rt_1_relay_192.168.x.x_48864: DropFrame called from ReadFn - drop 0991000000060b0432dd0001
2022.09.05 12:25:06.205 5: SH10rt_1_relay: ParseDataString called from HandleResponse with data hex 07e2, type i, adr 13021
2022.09.05 12:25:06.206 5: SH10rt_1_relay: SplitDataString called from ParseDataString with data hex 07e2, type i, adr 13021, valuesLen 1
2022.09.05 12:25:06.206 5: SH10rt_1_relay: SplitDataString has no information about handling i13021
2022.09.05 12:25:06.207 5: SH10rt_1_relay: CreateDataObjects called from ParseDataString with objList
2022.09.05 12:25:06.207 5: SH10rt_1_relay: CreateDataObjects sortedList
2022.09.05 12:25:06.208 5: SH10rt_1_relay: ParseDataString created 0 readings
2022.09.05 12:25:06.209 5: SH10rt_1_relay_192.168.x.x_48864: Send called from RelayResponse
2022.09.05 12:25:06.209 4: SH10rt_1_relay_192.168.x.x_48864: Send 0991000000050b040207e2
2022.09.05 12:25:06.216 5: SH10rt_1_relay_192.168.x.x_48864: readFn buffer: 0992000000060b0432c80001
2022.09.05 12:25:06.216 5: SH10rt_1_relay_192.168.x.x_48864: ParseFrameStart called from ReadFn protocol TCP expecting id 11
2022.09.05 12:25:06.217 4: SH10rt_1_relay_192.168.x.x_48864: ParseFrameStart (TCP, relay) extracted id 11, fCode 4, tid 2450, dlen 6 and potential data 32c80001
2022.09.05 12:25:06.217 5: SH10rt_1_relay_192.168.x.x_48864: HandleRequest called from ReadFn
2022.09.05 12:25:06.218 5: SH10rt_1_relay_192.168.x.x_48864: ParseRequest called from HandleRequest
2022.09.05 12:25:06.218 4: SH10rt_1_relay_192.168.x.x_48864: HandleRequest, current frame / read buffer: 0992000000060b0432c80001, id 11, fCode 4, tid 2450,
request: id 11 fc 4 i13000, len 1, tid 2450
2022.09.05 12:25:06.219 4: SH10rt_1_relay_192.168.x.x_48864: RelayRequest called from HandleRequest
2022.09.05 12:25:06.220 5: SH10rt_1_relay: GetRelayIO found SH10rt_1 as Modbus relay forward io device for SH10rt_1 with id 1
2022.09.05 12:25:06.220 4: SH10rt_1_relay_192.168.x.x_48864: RelayRequest via SH10rt_1, Proto TCP with id 1, current frame / read buffer: 0992000000060b0432c80001, id 11, fCode 4, tid 2450,
request: id 11 fc 4 i13000, len 1, tid 2450, for relay device SH10rt_1_relay_192.168.x.x_48864
2022.09.05 12:25:06.307 4: SH10rt_1_relay_192.168.x.x_48864: HandleRequest Done, current frame / read buffer: 0992000000060b0432c80001, id 11, fCode 4, tid 2450,
request: id 11 fc 4 i13000, len 1, tid 2450, for relay device SH10rt_1_relay_192.168.x.x_48864
2022.09.05 12:25:06.308 5: SH10rt_1_relay_192.168.x.x_48864: DropFrame called from ReadFn - drop 0992000000060b0432c80001
2022.09.05 12:25:06.319 5: SH10rt_1_relay: ParseDataString called from HandleResponse with data hex 0000, type i, adr 13000
2022.09.05 12:25:06.320 5: SH10rt_1_relay: SplitDataString called from ParseDataString with data hex 0000, type i, adr 13000, valuesLen 1
2022.09.05 12:25:06.320 5: SH10rt_1_relay: SplitDataString has no information about handling i13000
2022.09.05 12:25:06.321 5: SH10rt_1_relay: CreateDataObjects called from ParseDataString with objList
2022.09.05 12:25:06.321 5: SH10rt_1_relay: CreateDataObjects sortedList
2022.09.05 12:25:06.321 5: SH10rt_1_relay: ParseDataString created 0 readings
2022.09.05 12:25:06.322 5: SH10rt_1_relay_192.168.x.x_48864: Send called from RelayResponse
2022.09.05 12:25:06.322 4: SH10rt_1_relay_192.168.x.x_48864: Send 0992000000050b04020000
2022.09.05 12:25:06.328 5: SH10rt_1_relay_192.168.x.x_48864: readFn buffer: 0993000000060b0432c80001
2022.09.05 12:25:06.328 5: SH10rt_1_relay_192.168.x.x_48864: ParseFrameStart called from ReadFn protocol TCP expecting id 11
2022.09.05 12:25:06.329 4: SH10rt_1_relay_192.168.x.x_48864: ParseFrameStart (TCP, relay) extracted id 11, fCode 4, tid 2451, dlen 6 and potential data 32c80001
2022.09.05 12:25:06.329 5: SH10rt_1_relay_192.168.x.x_48864: HandleRequest called from ReadFn
2022.09.05 12:25:06.329 5: SH10rt_1_relay_192.168.x.x_48864: ParseRequest called from HandleRequest
2022.09.05 12:25:06.330 4: SH10rt_1_relay_192.168.x.x_48864: HandleRequest, current frame / read buffer: 0993000000060b0432c80001, id 11, fCode 4, tid 2451,
request: id 11 fc 4 i13000, len 1, tid 2451
2022.09.05 12:25:06.330 4: SH10rt_1_relay_192.168.x.x_48864: RelayRequest called from HandleRequest
2022.09.05 12:25:06.331 5: SH10rt_1_relay: GetRelayIO found SH10rt_1 as Modbus relay forward io device for SH10rt_1 with id 1
2022.09.05 12:25:06.331 4: SH10rt_1_relay_192.168.x.x_48864: RelayRequest via SH10rt_1, Proto TCP with id 1, current frame / read buffer: 0993000000060b0432c80001, id 11, fCode 4, tid 2451,
request: id 11 fc 4 i13000, len 1, tid 2451, for relay device SH10rt_1_relay_192.168.x.x_48864
2022.09.05 12:25:06.422 4: SH10rt_1_relay_192.168.x.x_48864: HandleRequest Done, current frame / read buffer: 0993000000060b0432c80001, id 11, fCode 4, tid 2451,
request: id 11 fc 4 i13000, len 1, tid 2451, for relay device SH10rt_1_relay_192.168.x.x_48864
2022.09.05 12:25:06.422 5: SH10rt_1_relay_192.168.x.x_48864: DropFrame called from ReadFn - drop 0993000000060b0432c80001
2022.09.05 12:25:06.434 5: SH10rt_1_relay: ParseDataString called from HandleResponse with data hex 0000, type i, adr 13000
2022.09.05 12:25:06.434 5: SH10rt_1_relay: SplitDataString called from ParseDataString with data hex 0000, type i, adr 13000, valuesLen 1
2022.09.05 12:25:06.435 5: SH10rt_1_relay: SplitDataString has no information about handling i13000
2022.09.05 12:25:06.435 5: SH10rt_1_relay: CreateDataObjects called from ParseDataString with objList
2022.09.05 12:25:06.435 5: SH10rt_1_relay: CreateDataObjects sortedList
2022.09.05 12:25:06.436 5: SH10rt_1_relay: ParseDataString created 0 readings
2022.09.05 12:25:06.437 5: SH10rt_1_relay_192.168.x.x_48864: Send called from RelayResponse
2022.09.05 12:25:06.437 4: SH10rt_1_relay_192.168.x.x_48864: Send 0993000000050b04020000
2022.09.05 12:25:06.442 5: SH10rt_1_relay_192.168.x.x_48864: readFn buffer: 0994000000060b0432d10002
2022.09.05 12:25:06.443 5: SH10rt_1_relay_192.168.x.x_48864: ParseFrameStart called from ReadFn protocol TCP expecting id 11
2022.09.05 12:25:06.443 4: SH10rt_1_relay_192.168.x.x_48864: ParseFrameStart (TCP, relay) extracted id 11, fCode 4, tid 2452, dlen 6 and potential data 32d10002
2022.09.05 12:25:06.444 5: SH10rt_1_relay_192.168.x.x_48864: HandleRequest called from ReadFn
2022.09.05 12:25:06.444 5: SH10rt_1_relay_192.168.x.x_48864: ParseRequest called from HandleRequest
2022.09.05 12:25:06.444 4: SH10rt_1_relay_192.168.x.x_48864: HandleRequest, current frame / read buffer: 0994000000060b0432d10002, id 11, fCode 4, tid 2452,
request: id 11 fc 4 i13009, len 2, tid 2452
2022.09.05 12:25:06.445 4: SH10rt_1_relay_192.168.x.x_48864: RelayRequest called from HandleRequest
2022.09.05 12:25:06.445 5: SH10rt_1_relay: GetRelayIO found SH10rt_1 as Modbus relay forward io device for SH10rt_1 with id 1
2022.09.05 12:25:06.446 4: SH10rt_1_relay_192.168.x.x_48864: RelayRequest via SH10rt_1, Proto TCP with id 1, current frame / read buffer: 0994000000060b0432d10002, id 11, fCode 4, tid 2452,
request: id 11 fc 4 i13009, len 2, tid 2452, for relay device SH10rt_1_relay_192.168.x.x_48864
2022.09.05 12:25:06.536 4: SH10rt_1_relay_192.168.x.x_48864: HandleRequest Done, current frame / read buffer: 0994000000060b0432d10002, id 11, fCode 4, tid 2452,
request: id 11 fc 4 i13009, len 2, tid 2452, for relay device SH10rt_1_relay_192.168.x.x_48864
2022.09.05 12:25:06.537 5: SH10rt_1_relay_192.168.x.x_48864: DropFrame called from ReadFn - drop 0994000000060b0432d10002
2022.09.05 12:25:06.556 5: SH10rt_1_relay: ParseDataString called from HandleResponse with data hex 01910000, type i, adr 13009
2022.09.05 12:25:06.556 5: SH10rt_1_relay: SplitDataString called from ParseDataString with data hex 01910000, type i, adr 13009, valuesLen 2
2022.09.05 12:25:06.556 5: SH10rt_1_relay: SplitDataString has no information about handling i13009
2022.09.05 12:25:06.557 5: SH10rt_1_relay: SplitDataString has no information about handling i13010
2022.09.05 12:25:06.557 5: SH10rt_1_relay: CreateDataObjects called from ParseDataString with objList
2022.09.05 12:25:06.557 5: SH10rt_1_relay: CreateDataObjects sortedList
2022.09.05 12:25:06.558 5: SH10rt_1_relay: ParseDataString created 0 readings
2022.09.05 12:25:06.559 5: SH10rt_1_relay_192.168.x.x_48864: Send called from RelayResponse
2022.09.05 12:25:06.559 4: SH10rt_1_relay_192.168.x.x_48864: Send 0994000000070b040401910000
2022.09.05 12:25:06.570 5: SH10rt_1_relay_192.168.x.x_48864: readFn buffer: 0995000000060b0432de0001
2022.09.05 12:25:06.571 5: SH10rt_1_relay_192.168.x.x_48864: ParseFrameStart called from ReadFn protocol TCP expecting id 11
2022.09.05 12:25:06.571 4: SH10rt_1_relay_192.168.x.x_48864: ParseFrameStart (TCP, relay) extracted id 11, fCode 4, tid 2453, dlen 6 and potential data 32de0001
2022.09.05 12:25:06.571 5: SH10rt_1_relay_192.168.x.x_48864: HandleRequest called from ReadFn
2022.09.05 12:25:06.572 5: SH10rt_1_relay_192.168.x.x_48864: ParseRequest called from HandleRequest
2022.09.05 12:25:06.572 4: SH10rt_1_relay_192.168.x.x_48864: HandleRequest, current frame / read buffer: 0995000000060b0432de0001, id 11, fCode 4, tid 2453,
request: id 11 fc 4 i13022, len 1, tid 2453
2022.09.05 12:25:06.573 4: SH10rt_1_relay_192.168.x.x_48864: RelayRequest called from HandleRequest
2022.09.05 12:25:06.573 5: SH10rt_1_relay: GetRelayIO found SH10rt_1 as Modbus relay forward io device for SH10rt_1 with id 1
2022.09.05 12:25:06.573 4: SH10rt_1_relay_192.168.x.x_48864: RelayRequest via SH10rt_1, Proto TCP with id 1, current frame / read buffer: 0995000000060b0432de0001, id 11, fCode 4, tid 2453,
request: id 11 fc 4 i13022, len 1, tid 2453, for relay device SH10rt_1_relay_192.168.x.x_48864
2022.09.05 12:25:06.658 4: SH10rt_1_relay_192.168.x.x_48864: HandleRequest Done, current frame / read buffer: 0995000000060b0432de0001, id 11, fCode 4, tid 2453,
request: id 11 fc 4 i13022, len 1, tid 2453, for relay device SH10rt_1_relay_192.168.x.x_48864
2022.09.05 12:25:06.659 5: SH10rt_1_relay_192.168.x.x_48864: DropFrame called from ReadFn - drop 0995000000060b0432de0001
2022.09.05 12:25:06.668 5: SH10rt_1_relay: ParseDataString called from HandleResponse with data hex 0348, type i, adr 13022
2022.09.05 12:25:06.669 5: SH10rt_1_relay: SplitDataString called from ParseDataString with data hex 0348, type i, adr 13022, valuesLen 1
2022.09.05 12:25:06.669 5: SH10rt_1_relay: SplitDataString has no information about handling i13022
2022.09.05 12:25:06.669 5: SH10rt_1_relay: CreateDataObjects called from ParseDataString with objList
2022.09.05 12:25:06.670 5: SH10rt_1_relay: CreateDataObjects sortedList
2022.09.05 12:25:06.670 5: SH10rt_1_relay: ParseDataString created 0 readings
2022.09.05 12:25:06.671 5: SH10rt_1_relay_192.168.x.x_48864: Send called from RelayResponse
2022.09.05 12:25:06.671 4: SH10rt_1_relay_192.168.x.x_48864: Send 0995000000050b04020348
2022.09.05 12:25:11.562 3: SH10rt_1_relay_192.168.x.x_48864: read from TCP server connection got null -> closing
2022.09.05 12:25:11.562 3: SH10rt_1_relay_192.168.x.x_48864: _UnDef is closing SH10rt_1_relay_192.168.x.x_48864
2022.09.05 12:25:11.563 5: SH10rt_1_relay_192.168.x.x_48864: Close called from UndefLDFn with noState and noDelete
2022.09.05 12:25:11.563 4: SH10rt_1_relay_192.168.x.x_48864: Close TCP server listening connection and delete hash
2022.09.05 12:25:11.730 5: SH10rt_1_relay_192.168.x.x_48864: Close is removing lastconn from parent device SH10rt_1_relay
2022.09.05 12:25:15.027 4: Connection accepted from SH10rt_1_relay_192.168.x.x_48870
2022.09.05 12:25:15.028 4: SH10rt_1_relay: HandleServerConnection accepted new TCP connection as device SH10rt_1_relay_192.168.x.x_48870
2022.09.05 12:25:15.119 5: SH10rt_1_relay_192.168.x.x_48870: readFn buffer: 0996000000060b0413980002
2022.09.05 12:25:15.119 5: SH10rt_1_relay_192.168.x.x_48870: ParseFrameStart called from ReadFn
2022.09.05 12:25:15.120 4: SH10rt_1_relay_192.168.x.x_48870: ParseFrameStart (TCP, relay) extracted id 11, fCode 4, tid 2454, dlen 6 and potential data 13980002
2022.09.05 12:25:15.120 5: SH10rt_1_relay_192.168.x.x_48870: HandleRequest called from ReadFn
2022.09.05 12:25:15.121 5: SH10rt_1_relay_192.168.x.x_48870: ParseRequest called from HandleRequest
2022.09.05 12:25:15.122 4: SH10rt_1_relay_192.168.x.x_48870: HandleRequest, current frame / read buffer: 0996000000060b0413980002, id 11, fCode 4, tid 2454,
request: id 11 fc 4 i5016, len 2, tid 2454
2022.09.05 12:25:15.122 4: SH10rt_1_relay_192.168.x.x_48870: RelayRequest called from HandleRequest
2022.09.05 12:25:15.123 5: SH10rt_1_relay: GetRelayIO found SH10rt_1 as Modbus relay forward io device for SH10rt_1 with id 1
2022.09.05 12:25:15.123 4: SH10rt_1_relay_192.168.x.x_48870: RelayRequest via SH10rt_1, Proto TCP with id 1, current frame / read buffer: 0996000000060b0413980002, id 11, fCode 4, tid 2454,
request: id 11 fc 4 i5016, len 2, tid 2454, for relay device SH10rt_1_relay_192.168.x.x_48870
2022.09.05 12:25:15.130 4: SH10rt_1_relay_192.168.x.x_48870: HandleRequest Done, current frame / read buffer: 0996000000060b0413980002, id 11, fCode 4, tid 2454,
request: id 11 fc 4 i5016, len 2, tid 2454, for relay device SH10rt_1_relay_192.168.x.x_48870
2022.09.05 12:25:15.131 5: SH10rt_1_relay_192.168.x.x_48870: DropFrame called from ReadFn - drop 0996000000060b0413980002
2022.09.05 12:25:15.153 5: SH10rt_1_relay: ParseDataString called from HandleResponse with data hex 1d030000, type i, adr 5016
2022.09.05 12:25:15.154 5: SH10rt_1_relay: SplitDataString called from ParseDataString with data hex 1d030000, type i, adr 5016, valuesLen 2
2022.09.05 12:25:15.154 5: SH10rt_1_relay: SplitDataString has no information about handling i5016
2022.09.05 12:25:15.155 5: SH10rt_1_relay: SplitDataString has no information about handling i5017
2022.09.05 12:25:15.155 5: SH10rt_1_relay: CreateDataObjects called from ParseDataString with objList
2022.09.05 12:25:15.155 5: SH10rt_1_relay: CreateDataObjects sortedList
2022.09.05 12:25:15.156 5: SH10rt_1_relay: ParseDataString created 0 readings
2022.09.05 12:25:15.157 5: SH10rt_1_relay_192.168.x.x_48870: Send called from RelayResponse
2022.09.05 12:25:15.157 4: SH10rt_1_relay_192.168.x.x_48870: Send 0996000000070b04041d030000
2022.09.05 12:25:15.232 5: SH10rt_1_relay_192.168.x.x_48870: readFn buffer: 0997000000060b0432dd0001
2022.09.05 12:25:15.233 5: SH10rt_1_relay_192.168.x.x_48870: ParseFrameStart called from ReadFn protocol TCP expecting id 11
2022.09.05 12:25:15.233 4: SH10rt_1_relay_192.168.x.x_48870: ParseFrameStart (TCP, relay) extracted id 11, fCode 4, tid 2455, dlen 6 and potential data 32dd0001
2022.09.05 12:25:15.233 5: SH10rt_1_relay_192.168.x.x_48870: HandleRequest called from ReadFn
2022.09.05 12:25:15.234 5: SH10rt_1_relay_192.168.x.x_48870: ParseRequest called from HandleRequest
2022.09.05 12:25:15.234 4: SH10rt_1_relay_192.168.x.x_48870: HandleRequest, current frame / read buffer: 0997000000060b0432dd0001, id 11, fCode 4, tid 2455,
request: id 11 fc 4 i13021, len 1, tid 2455
2022.09.05 12:25:15.235 4: SH10rt_1_relay_192.168.x.x_48870: RelayRequest called from HandleRequest
2022.09.05 12:25:15.235 5: SH10rt_1_relay: GetRelayIO found SH10rt_1 as Modbus relay forward io device for SH10rt_1 with id 1
2022.09.05 12:25:15.235 4: SH10rt_1_relay_192.168.x.x_48870: RelayRequest via SH10rt_1, Proto TCP with id 1, current frame / read buffer: 0997000000060b0432dd0001, id 11, fCode 4, tid 2455,
request: id 11 fc 4 i13021, len 1, tid 2455, for relay device SH10rt_1_relay_192.168.x.x_48870
2022.09.05 12:25:15.241 4: SH10rt_1_relay_192.168.x.x_48870: HandleRequest Done, current frame / read buffer: 0997000000060b0432dd0001, id 11, fCode 4, tid 2455,
request: id 11 fc 4 i13021, len 1, tid 2455, for relay device SH10rt_1_relay_192.168.x.x_48870
2022.09.05 12:25:15.242 5: SH10rt_1_relay_192.168.x.x_48870: DropFrame called from ReadFn - drop 0997000000060b0432dd0001
2022.09.05 12:25:15.246 5: SH10rt_1_relay: ParseDataString called from HandleResponse with data hex 07e2, type i, adr 13021
2022.09.05 12:25:15.246 5: SH10rt_1_relay: SplitDataString called from ParseDataString with data hex 07e2, type i, adr 13021, valuesLen 1
2022.09.05 12:25:15.247 5: SH10rt_1_relay: SplitDataString has no information about handling i13021
2022.09.05 12:25:15.247 5: SH10rt_1_relay: CreateDataObjects called from ParseDataString with objList
2022.09.05 12:25:15.247 5: SH10rt_1_relay: CreateDataObjects sortedList
2022.09.05 12:25:15.248 5: SH10rt_1_relay: ParseDataString created 0 readings
2022.09.05 12:25:15.248 5: SH10rt_1_relay_192.168.x.x_48870: Send called from RelayResponse
2022.09.05 12:25:15.249 4: SH10rt_1_relay_192.168.x.x_48870: Send 0997000000050b040207e2
2022.09.05 12:25:15.254 5: SH10rt_1_relay_192.168.x.x_48870: readFn buffer: 0998000000060b0432c80001
2022.09.05 12:25:15.254 5: SH10rt_1_relay_192.168.x.x_48870: ParseFrameStart called from ReadFn protocol TCP expecting id 11
2022.09.05 12:25:15.255 4: SH10rt_1_relay_192.168.x.x_48870: ParseFrameStart (TCP, relay) extracted id 11, fCode 4, tid 2456, dlen 6 and potential data 32c80001
2022.09.05 12:25:15.255 5: SH10rt_1_relay_192.168.x.x_48870: HandleRequest called from ReadFn
2022.09.05 12:25:15.255 5: SH10rt_1_relay_192.168.x.x_48870: ParseRequest called from HandleRequest
2022.09.05 12:25:15.256 4: SH10rt_1_relay_192.168.x.x_48870: HandleRequest, current frame / read buffer: 0998000000060b0432c80001, id 11, fCode 4, tid 2456,
request: id 11 fc 4 i13000, len 1, tid 2456
2022.09.05 12:25:15.256 4: SH10rt_1_relay_192.168.x.x_48870: RelayRequest called from HandleRequest
2022.09.05 12:25:15.257 5: SH10rt_1_relay: GetRelayIO found SH10rt_1 as Modbus relay forward io device for SH10rt_1 with id 1
2022.09.05 12:25:15.257 4: SH10rt_1_relay_192.168.x.x_48870: RelayRequest via SH10rt_1, Proto TCP with id 1, current frame / read buffer: 0998000000060b0432c80001, id 11, fCode 4, tid 2456,
request: id 11 fc 4 i13000, len 1, tid 2456, for relay device SH10rt_1_relay_192.168.x.x_48870
2022.09.05 12:25:15.348 4: SH10rt_1_relay_192.168.x.x_48870: HandleRequest Done, current frame / read buffer: 0998000000060b0432c80001, id 11, fCode 4, tid 2456,
request: id 11 fc 4 i13000, len 1, tid 2456, for relay device SH10rt_1_relay_192.168.x.x_48870
2022.09.05 12:25:15.349 5: SH10rt_1_relay_192.168.x.x_48870: DropFrame called from ReadFn - drop 0998000000060b0432c80001
2022.09.05 12:25:15.356 5: SH10rt_1_relay: ParseDataString called from HandleResponse with data hex 0000, type i, adr 13000
2022.09.05 12:25:15.357 5: SH10rt_1_relay: SplitDataString called from ParseDataString with data hex 0000, type i, adr 13000, valuesLen 1
2022.09.05 12:25:15.357 5: SH10rt_1_relay: SplitDataString has no information about handling i13000
2022.09.05 12:25:15.358 5: SH10rt_1_relay: CreateDataObjects called from ParseDataString with objList
2022.09.05 12:25:15.358 5: SH10rt_1_relay: CreateDataObjects sortedList
2022.09.05 12:25:15.358 5: SH10rt_1_relay: ParseDataString created 0 readings
2022.09.05 12:25:15.359 5: SH10rt_1_relay_192.168.x.x_48870: Send called from RelayResponse
2022.09.05 12:25:15.359 4: SH10rt_1_relay_192.168.x.x_48870: Send 0998000000050b04020000
2022.09.05 12:25:15.365 5: SH10rt_1_relay_192.168.x.x_48870: readFn buffer: 0999000000060b0432c80001
2022.09.05 12:25:15.365 5: SH10rt_1_relay_192.168.x.x_48870: ParseFrameStart called from ReadFn protocol TCP expecting id 11
2022.09.05 12:25:15.366 4: SH10rt_1_relay_192.168.x.x_48870: ParseFrameStart (TCP, relay) extracted id 11, fCode 4, tid 2457, dlen 6 and potential data 32c80001
2022.09.05 12:25:15.366 5: SH10rt_1_relay_192.168.x.x_48870: HandleRequest called from ReadFn
2022.09.05 12:25:15.366 5: SH10rt_1_relay_192.168.x.x_48870: ParseRequest called from HandleRequest
2022.09.05 12:25:15.367 4: SH10rt_1_relay_192.168.x.x_48870: HandleRequest, current frame / read buffer: 0999000000060b0432c80001, id 11, fCode 4, tid 2457,
request: id 11 fc 4 i13000, len 1, tid 2457
2022.09.05 12:25:15.367 4: SH10rt_1_relay_192.168.x.x_48870: RelayRequest called from HandleRequest
2022.09.05 12:25:15.368 5: SH10rt_1_relay: GetRelayIO found SH10rt_1 as Modbus relay forward io device for SH10rt_1 with id 1
2022.09.05 12:25:15.368 4: SH10rt_1_relay_192.168.x.x_48870: RelayRequest via SH10rt_1, Proto TCP with id 1, current frame / read buffer: 0999000000060b0432c80001, id 11, fCode 4, tid 2457,
request: id 11 fc 4 i13000, len 1, tid 2457, for relay device SH10rt_1_relay_192.168.x.x_48870
2022.09.05 12:25:15.458 4: SH10rt_1_relay_192.168.x.x_48870: HandleRequest Done, current frame / read buffer: 0999000000060b0432c80001, id 11, fCode 4, tid 2457,
request: id 11 fc 4 i13000, len 1, tid 2457, for relay device SH10rt_1_relay_192.168.x.x_48870
2022.09.05 12:25:15.458 5: SH10rt_1_relay_192.168.x.x_48870: DropFrame called from ReadFn - drop 0999000000060b0432c80001
2022.09.05 12:25:15.463 5: SH10rt_1_relay: ParseDataString called from HandleResponse with data hex 0000, type i, adr 13000
2022.09.05 12:25:15.463 5: SH10rt_1_relay: SplitDataString called from ParseDataString with data hex 0000, type i, adr 13000, valuesLen 1
2022.09.05 12:25:15.464 5: SH10rt_1_relay: SplitDataString has no information about handling i13000
2022.09.05 12:25:15.464 5: SH10rt_1_relay: CreateDataObjects called from ParseDataString with objList
2022.09.05 12:25:15.465 5: SH10rt_1_relay: CreateDataObjects sortedList
2022.09.05 12:25:15.465 5: SH10rt_1_relay: ParseDataString created 0 readings
2022.09.05 12:25:15.466 5: SH10rt_1_relay_192.168.x.x_48870: Send called from RelayResponse
2022.09.05 12:25:15.466 4: SH10rt_1_relay_192.168.x.x_48870: Send 0999000000050b04020000
2022.09.05 12:25:15.471 5: SH10rt_1_relay_192.168.x.x_48870: readFn buffer: 099a000000060b0432d10002
2022.09.05 12:25:15.472 5: SH10rt_1_relay_192.168.x.x_48870: ParseFrameStart called from ReadFn protocol TCP expecting id 11
2022.09.05 12:25:15.472 4: SH10rt_1_relay_192.168.x.x_48870: ParseFrameStart (TCP, relay) extracted id 11, fCode 4, tid 2458, dlen 6 and potential data 32d10002
2022.09.05 12:25:15.473 5: SH10rt_1_relay_192.168.x.x_48870: HandleRequest called from ReadFn
2022.09.05 12:25:15.473 5: SH10rt_1_relay_192.168.x.x_48870: ParseRequest called from HandleRequest
2022.09.05 12:25:15.474 4: SH10rt_1_relay_192.168.x.x_48870: HandleRequest, current frame / read buffer: 099a000000060b0432d10002, id 11, fCode 4, tid 2458,
request: id 11 fc 4 i13009, len 2, tid 2458
2022.09.05 12:25:15.474 4: SH10rt_1_relay_192.168.x.x_48870: RelayRequest called from HandleRequest
2022.09.05 12:25:15.474 5: SH10rt_1_relay: GetRelayIO found SH10rt_1 as Modbus relay forward io device for SH10rt_1 with id 1
2022.09.05 12:25:15.475 4: SH10rt_1_relay_192.168.x.x_48870: RelayRequest via SH10rt_1, Proto TCP with id 1, current frame / read buffer: 099a000000060b0432d10002, id 11, fCode 4, tid 2458,
request: id 11 fc 4 i13009, len 2, tid 2458, for relay device SH10rt_1_relay_192.168.x.x_48870
2022.09.05 12:25:15.565 4: SH10rt_1_relay_192.168.x.x_48870: HandleRequest Done, current frame / read buffer: 099a000000060b0432d10002, id 11, fCode 4, tid 2458,
request: id 11 fc 4 i13009, len 2, tid 2458, for relay device SH10rt_1_relay_192.168.x.x_48870
2022.09.05 12:25:15.566 5: SH10rt_1_relay_192.168.x.x_48870: DropFrame called from ReadFn - drop 099a000000060b0432d10002
2022.09.05 12:25:15.586 5: SH10rt_1_relay: ParseDataString called from HandleResponse with data hex ffabffff, type i, adr 13009
2022.09.05 12:25:15.586 5: SH10rt_1_relay: SplitDataString called from ParseDataString with data hex ffabffff, type i, adr 13009, valuesLen 2
2022.09.05 12:25:15.587 5: SH10rt_1_relay: SplitDataString has no information about handling i13009
2022.09.05 12:25:15.587 5: SH10rt_1_relay: SplitDataString has no information about handling i13010
2022.09.05 12:25:15.587 5: SH10rt_1_relay: CreateDataObjects called from ParseDataString with objList
2022.09.05 12:25:15.588 5: SH10rt_1_relay: CreateDataObjects sortedList
2022.09.05 12:25:15.588 5: SH10rt_1_relay: ParseDataString created 0 readings
2022.09.05 12:25:15.589 5: SH10rt_1_relay_192.168.x.x_48870: Send called from RelayResponse
2022.09.05 12:25:15.589 4: SH10rt_1_relay_192.168.x.x_48870: Send 099a000000070b0404ffabffff
2022.09.05 12:25:15.595 5: SH10rt_1_relay_192.168.x.x_48870: readFn buffer: 099b000000060b0432de0001
2022.09.05 12:25:15.595 5: SH10rt_1_relay_192.168.x.x_48870: ParseFrameStart called from ReadFn protocol TCP expecting id 11
2022.09.05 12:25:15.596 4: SH10rt_1_relay_192.168.x.x_48870: ParseFrameStart (TCP, relay) extracted id 11, fCode 4, tid 2459, dlen 6 and potential data 32de0001
2022.09.05 12:25:15.596 5: SH10rt_1_relay_192.168.x.x_48870: HandleRequest called from ReadFn
2022.09.05 12:25:15.596 5: SH10rt_1_relay_192.168.x.x_48870: ParseRequest called from HandleRequest
2022.09.05 12:25:15.597 4: SH10rt_1_relay_192.168.x.x_48870: HandleRequest, current frame / read buffer: 099b000000060b0432de0001, id 11, fCode 4, tid 2459,
request: id 11 fc 4 i13022, len 1, tid 2459
2022.09.05 12:25:15.597 4: SH10rt_1_relay_192.168.x.x_48870: RelayRequest called from HandleRequest
2022.09.05 12:25:15.597 5: SH10rt_1_relay: GetRelayIO found SH10rt_1 as Modbus relay forward io device for SH10rt_1 with id 1
2022.09.05 12:25:15.598 4: SH10rt_1_relay_192.168.x.x_48870: RelayRequest via SH10rt_1, Proto TCP with id 1, current frame / read buffer: 099b000000060b0432de0001, id 11, fCode 4, tid 2459,
request: id 11 fc 4 i13022, len 1, tid 2459, for relay device SH10rt_1_relay_192.168.x.x_48870
2022.09.05 12:25:15.674 4: SH10rt_1_relay_192.168.x.x_48870: HandleRequest Done, current frame / read buffer: 099b000000060b0432de0001, id 11, fCode 4, tid 2459,
request: id 11 fc 4 i13022, len 1, tid 2459, for relay device SH10rt_1_relay_192.168.x.x_48870
2022.09.05 12:25:15.674 5: SH10rt_1_relay_192.168.x.x_48870: DropFrame called from ReadFn - drop 099b000000060b0432de0001
2022.09.05 12:25:15.679 5: SH10rt_1_relay: ParseDataString called from HandleResponse with data hex 0348, type i, adr 13022
2022.09.05 12:25:15.680 5: SH10rt_1_relay: SplitDataString called from ParseDataString with data hex 0348, type i, adr 13022, valuesLen 1
2022.09.05 12:25:15.680 5: SH10rt_1_relay: SplitDataString has no information about handling i13022
2022.09.05 12:25:15.681 5: SH10rt_1_relay: CreateDataObjects called from ParseDataString with objList
2022.09.05 12:25:15.681 5: SH10rt_1_relay: CreateDataObjects sortedList
2022.09.05 12:25:15.681 5: SH10rt_1_relay: ParseDataString created 0 readings
2022.09.05 12:25:15.682 5: SH10rt_1_relay_192.168.x.x_48870: Send called from RelayResponse
2022.09.05 12:25:15.682 4: SH10rt_1_relay_192.168.x.x_48870: Send 099b000000050b04020348
2022.09.05 12:25:20.760 3: SH10rt_1_relay_192.168.x.x_48870: read from TCP server connection got null -> closing
2022.09.05 12:25:20.761 3: SH10rt_1_relay_192.168.x.x_48870: _UnDef is closing SH10rt_1_relay_192.168.x.x_48870
2022.09.05 12:25:20.761 5: SH10rt_1_relay_192.168.x.x_48870: Close called from UndefLDFn with noState and noDelete
2022.09.05 12:25:20.761 4: SH10rt_1_relay_192.168.x.x_48870: Close TCP server listening connection and delete hash
2022.09.05 12:25:20.938 5: SH10rt_1_relay_192.168.x.x_48870: Close is removing lastconn from parent device SH10rt_1_relay

Und ein Log während ich mit EVCC lade:

[code]2022.09.05 13:25:08.317 5: SH10rt_1_relay: UpdateSetList: setList=reconnect:noArg saveAsModule createAttrsFromParseInfo inactive active
2022.09.05 13:25:08.317 5: SH10rt_1_relay: UpdateSetList: getList=
2022.09.05 13:25:11.040 3: SH10rt_1_relay_192.168.x.x_57356: read from TCP server connection got null -> closing
2022.09.05 13:25:11.040 3: SH10rt_1_relay_192.168.x.x_57356: _UnDef is closing SH10rt_1_relay_192.168.x.x_57356
2022.09.05 13:25:11.046 5: SH10rt_1_relay_192.168.x.x_57356: Close called from UndefLDFn with noState and noDelete
2022.09.05 13:25:11.047 4: SH10rt_1_relay_192.168.x.x_57356: Close TCP server listening connection and delete hash
2022.09.05 13:25:11.051 5: SH10rt_1_relay_192.168.x.x_57356: Close is removing lastconn from parent device SH10rt_1_relay
2022.09.05 13:25:15.031 4: Connection accepted from SH10rt_1_relay_192.168.x.x_57362
2022.09.05 13:25:15.032 4: SH10rt_1_relay: HandleServerConnection accepted new TCP connection as device SH10rt_1_relay_192.168.x.x_57362
2022.09.05 13:25:15.145 5: SH10rt_1_relay_192.168.x.x_57362: readFn buffer: 125c000000060b0413980002
2022.09.05 13:25:15.146 5: SH10rt_1_relay_192.168.x.x_57362: ParseFrameStart called from ReadFn
2022.09.05 13:25:15.147 4: SH10rt_1_relay_192.168.x.x_57362: ParseFrameStart (TCP, relay) extracted id 11, fCode 4, tid 4700, dlen 6 and potential data 13980002
2022.09.05 13:25:15.147 5: SH10rt_1_relay_192.168.x.x_57362: HandleRequest called from ReadFn
2022.09.05 13:25:15.148 5: SH10rt_1_relay_192.168.x.x_57362: ParseRequest called from HandleRequest
2022.09.05 13:25:15.149 4: SH10rt_1_relay_192.168.x.x_57362: HandleRequest, current frame / read buffer: 125c000000060b0413980002, id 11, fCode 4, tid 4700,
request: id 11 fc 4 i5016, len 2, tid 4700
2022.09.05 13:25:15.150 4: SH10rt_1_relay_192.168.x.x_57362: RelayRequest called from HandleRequest
2022.09.05 13:25:15.151 5: SH10rt_1_relay: GetRelayIO found SH10rt_1 as Modbus relay forward io device for SH10rt_1 with id 1
2022.09.05 13:25:15.152 4: SH10rt_1_relay_192.168.x.x_57362: RelayRequest via SH10rt_1, Proto TCP with id 1, current frame / read buffer: 125c000000060b0413980002, id 11, fCode 4, tid 4700,
request: id 11 fc 4 i5016, len 2, tid 4700, for relay device SH10rt_1_relay_192.168.x.x_57362
2022.09.05 13:25:15.162 4: SH10rt_1_relay_192.168.x.x_57362: HandleRequest Done, current frame / read buffer: 125c000000060b0413980002, id 11, fCode 4, tid 4700,
request: id 11 fc 4 i5016, len 2, tid 4700, for relay device SH10rt_1_relay_192.168.x.x_57362
2022.09.05 13:25:15.163 5: SH10rt_1_relay_192.168.x.x_57362: DropFrame called from ReadFn - drop 125c000000060b0413980002
2022.09.05 13:25:15.220 5: SH10rt_1_relay: ParseDataString called from HandleResponse with data hex 1bc30000, type i, adr 5016
2022.09.05 13:25:15.220 5: SH10rt_1_relay: SplitDataString called from ParseDataString with data hex 1bc30000, type i, adr 5016, valuesLen 2
2022.09.05 13:25:15.221 5: SH10rt_1_relay: SplitDataString has no information about handling i5016
2022.09.05 13:25:15.221 5: SH10rt_1_relay: SplitDataString has no information about handling i5017
2022.09.05 13:25:15.221 5: SH10rt_1_relay: CreateDataObjects called from ParseDataString with objList
2022.09.05 13:25:15.221 5: SH10rt_1_relay: CreateDataObjects sortedList
2022.09.05 13:25:15.222 5: SH10rt_1_relay: ParseDataString created 0 readings
2022.09.05 13:25:15.222 5: SH10rt_1_relay_192.168.x.x_57362: Send called from RelayResponse
2022.09.05 13:25:15.223 4: SH10rt_1_relay_192.168.x.x_57362: Send 125c000000070b04041bc30000
2022.09.05 13:25:15.316 5: SH10rt_1_relay_192.168.x.x_57362: readFn buffer: 125d000000060b0432dd0001
2022.09.05 13:25:15.316 5: SH10rt_1_relay_192.168.x.x_57362: ParseFrameStart called from ReadFn protocol TCP expecting id 11
2022.09.05 13:25:15.316 4: SH10rt_1_relay_192.168.x.x_57362: ParseFrameStart (TCP, relay) extracted id 11, fCode 4, tid 4701, dlen 6 and potential data 32dd0001
2022.09.05 13:25:15.317 5: SH10rt_1_relay_192.168.x.x_57362: HandleRequest called from ReadFn
2022.09.05 13:25:15.317 5: SH10rt_1_relay_192.168.x.x_57362: ParseRequest called from HandleRequest
2022.09.05 13:25:15.317 4: SH10rt_1_relay_192.168.x.x_57362: HandleRequest, current frame / read buffer: 125d000000060b0432dd0001, id 11, fCode 4, tid 4701,
request: id 11 fc 4 i13021, len 1, tid 4701
2022.09.05 13:25:15.318 4: SH10rt_1_relay_192.168.x.x_57362: RelayRequest called from HandleRequest
2022.09.05 13:25:15.318 5: SH10rt_1_relay: GetRelayIO found SH10rt_1 as Modbus relay forward io device for SH10rt_1 with id 1
2022.09.05 13:25:15.318 4: SH10rt_1_relay_192.168.x.x_57362: RelayRequest via SH10rt_1, Proto TCP with id 1, current frame / read buffer: 125d000000060b0432dd0001, id 11, fCode 4, tid 4701,
request: id 11 fc 4 i13021, len 1, tid 4701, for relay device SH10rt_1_relay_192.168.x.x_57362
2022.09.05 13:25:15.324 4: SH10rt_1_relay_192.168.x.x_57362: HandleRequest Done, current frame / read buffer: 125d000000060b0432dd0001, id 11, fCode 4, tid 4701,
request: id 11 fc 4 i13021, len 1, tid 4701, for relay device SH10rt_1_relay_192.168.x.x_57362
2022.09.05 13:25:15.324 5: SH10rt_1_relay_192.168.x.x_57362: DropFrame called from ReadFn - drop 125d000000060b0432dd0001
2022.09.05 13:25:15.329 5: SH10rt_1_relay: ParseDataString called from HandleResponse with data hex 0000, type i, adr 13021
2022.09.05 13:25:15.329 5: SH10rt_1_relay: SplitDataString called from ParseDataString with data hex 0000, type i, adr 13021, valuesLen 1
2022.09.05 13:25:15.329 5: SH10rt_1_relay: SplitDataString has no information about handling i13021
2022.09.05 13:25:15.329 5: SH10rt_1_relay: CreateDataObjects called from ParseDataString with objList
2022.09.05 13:25:15.330 5: SH10rt_1_relay: CreateDataObjects sortedList
2022.09.05 13:25:15.330 5: SH10rt_1_relay: ParseDataString created 0 readings
2022.09.05 13:25:15.331 5: SH10rt_1_relay_192.168.x.x_57362: Send called from RelayResponse
2022.09.05 13:25:15.331 4: SH10rt_1_relay_192.168.x.x_57362: Send 125d000000050b04020000
2022.09.05 13:25:15.336 5: SH10rt_1_relay_192.168.x.x_57362: readFn buffer: 125e000000060b0432c80001
2022.09.05 13:25:15.337 5: SH10rt_1_relay_192.168.x.x_57362: ParseFrameStart called from ReadFn protocol TCP expecting id 11
2022.09.05 13:25:15.337 4: SH10rt_1_relay_192.168.x.x_57362: ParseFrameStart (TCP, relay) extracted id 11, fCode 4, tid 4702, dlen 6 and potential data 32c80001
2022.09.05 13:25:15.337 5: SH10rt_1_relay_192.168.x.x_57362: HandleRequest called from ReadFn
2022.09.05 13:25:15.338 5: SH10rt_1_relay_192.168.x.x_57362: ParseRequest called from HandleRequest
2022.09.05 13:25:15.338 4: SH10rt_1_relay_192.168.x.x_57362: HandleRequest, current frame / read buffer: 125e000000060b0432c80001, id 11, fCode 4, tid 4702,
request: id 11 fc 4 i13000, len 1, tid 4702
2022.09.05 13:25:15.338 4: SH10rt_1_relay_192.168.x.x_57362: RelayRequest called from HandleRequest
2022.09.05 13:25:15.339 5: SH10rt_1_relay: GetRelayIO found SH10rt_1 as Modbus relay forward io device for SH10rt_1 with id 1
2022.09.05 13:25:15.339 4: SH10rt_1_relay_192.168.x.x_57362: RelayRequest via SH10rt_1, Proto TCP with id 1, current frame / read buffer: 125e000000060b0432c80001, id 11, fCode 4, tid 4702,
request: id 11 fc 4 i13000, len 1, tid 4702, for relay device SH10rt_1_relay_192.168.x.x_57362
2022.09.05 13:25:15.432 4: SH10rt_1_relay_192.168.x.x_57362: HandleRequest Done, current frame / read buffer: 125e000000060b0432c80001, id 11, fCode 4, tid 4702,
request: id 11 fc 4 i13000, len 1, tid 4702, for relay device SH10rt_1_relay_192.168.x.x_57362
2022.09.05 13:25:15.432 5: SH10rt_1_relay_192.168.x.x_57362: DropFrame called from ReadFn - drop 125e000000060b0432c80001
2022.09.05 13:25:15.470 5: SH10rt_1_relay: ParseDataString called from HandleResponse with data hex 0000, type i, adr 13000
2022.09.05 13:25:15.471 5: SH10rt_1_relay: SplitDataString called from ParseDataString with data hex 0000, type i, adr 13000, valuesLen 1
2022.09.05 13:25:

StefanStrobel · 05 September 2022, 18:23:35

Hallo FhemPiUser,

Für die Fehlersuche bräuchte ich nicht nur die Logs der Relay-Devices sondern parallel auch die der vom Relay verwendeten Master-Devices.

Um die Fehlersuche zu vereinfachen wäre es schön, wenn Du die Relay-Funktion mal von Deinen regulären Master-Abfragen trennen könntest. Dazu einfach alle Objekt-Attribute aus SH10rt_1 und SH0rt_2 entfernen und auch im Define das Intervall auf 0 setzen.
Dann haben wir nur noch die Relay-Funktion ohne eigene Parallele Abfragen und alle Requests kommen vom evcc.
Wenn dann immer noch der RAM-Verbrauch steigt, sollte das einfacher zu finden sein.

Zudem müsste ich wissen, welche Version des Moduls Du verwendest, sonst passen Deine Zeilennummern nicht zu meinen.

Gruß
Stefan