Neue Versionen und Support zum Modbus-Modul

[gadget]

Hallo,

Ich bleibe jetzt erst mal bei der ser2net Lösung. Ich hätte auch noch einen Elfin EE11, den ich auf Verdacht in China mitbestellt hatte. Das ist die Variante RS485 zu Ethernet (LAN). Wenn sich jemand berufen fühlt und das technische KnowHow hat sich da tiefer reinzufrickeln stelle ich den gerne zur Verfügung.

Grüße, gadget

[Mike73]

Hallo Mike,

schick doch mal einen Auszug aus dem Log bei verbose 5 (sowohl für die physischen als auch für die logischen Devices),
dann finden wir das Problem sicher.

Gruss
    Stefan

Hallo Stefan,

war leider ein paar Tage nicht dran. Ich habe jetzt die Logs gemacht und angehängt als Datei.

Ich hoffe, du kannst daraus was erkennen

Danke und Grüße

Mike 

[StefanStrobel]

Hallo Mike,

Leider fehlen einige Informationen im Log, primär auf der Seite des Relays.
Zum einen scheint das physische Modbus-Device MBGate nicht auf verbose 5 gestanden zu haben oder zumindest sehe ich nichts im Log und auf dieser Ebene findet das Relaying statt.

Zum anderen sehe ich auch die Kommunikation auf TCP-Ebene nicht im Log auf der Relay-Seite.

Kann es sein, dass Du verbose 5 erst gesetzt hast, als die TCP-Verbindung zwischen dem Slave und dem Relay schon geöffnet war? (Für die Verbindung wird intern ein neues Device erstellt, das dann von dem verbose-Attribut nichts mehr mitbekommt).

Du müsstest daher verbose 5 setzen, bevor die Verbindung geöffnet wird. Dann erbt das Verbindungs-Device die Attribute und dann sollte man im Log auch die Kommunikation innerhalb der TCP-Verbindung sehen.

Und dann ist es noch problematisch, dass das Relay selbst auch einen Update-Timer hat und gleichzeitig als eigenständiger Master Werte abfragt. Das war nicht so gedacht, könnte zwar klappen, macht aber die Fehlersuche schwieriger.
Eventuell kommen so aber die Requests durcheinander.
Daher würde ich vorschlagen, hier beim Define 0 als Intervall zu setzen. Eventuell löst das schon das Problem ...

Gruß
    Stefan

[Mike73]

Hallo Stefan,

vielen Dank dass Du Dir die Mühe gemacht hast. In der Tat - ich hatte beim MBGate kein verbose und auch das Öffnen nach dem Setzen des Attributes hatte ich nicht gemacht. Ich mach das nochmal ..

Zuvor teste ich aber den Hinweis mit dem Master+Relay und deaktiviere das Master-Device auf dem Relay-Host.

Ich melde mich dann mit den Ergebnissen

Einen schönen Tag !

Mike

[Mike73]

Hallo und guten Abend,

ich habe jetzt die beiden neuen Logs.
Zuvor habe ich den HKVEG1 auf dem Relay entrümpelt. Der sieht jetzt ganz blank aus und dürfte sich mit dem Relay nicht mehr in die Quere kommen.

def:

Code Auswählen Erweitern

defmod RelayHKVEG1 ModbusAttr 57 relay 192.168.3.15:1502 TCP to HKVEG1
attr RelayHKVEG1 room Modbus

list:

Code Auswählen Erweitern


Internals:
   CHANGED   
   CONNECTS   9
   DEF        57 relay 192.168.3.15:1502 TCP to HKVEG1
   DeviceName 192.168.3.15:1502
   EXPECT     request
   FD         11
   FUUID      5c759876-f33f-53e7-e63d-dbf32ea83003afce
   IODev      RelayHKVEG1
   LASTCONN   RelayHKVEG1_192.168.3.10_40724
   MODBUSID   57
   MODE       relay
   MODULEVERSION Modbus 4.1.5 - 17.9.2019
   NAME       RelayHKVEG1
   NOTIFYDEV  global
   NR         133
   NTFY_ORDER 50-RelayHKVEG1
   PORT       1502
   PROTOCOL   TCP
   RELAY      HKVEG1
   RELID      7
   STATE      opened
   TCPConn    1
   TCPServer  1
   TYPE       ModbusAttr
   CONNECTHASH:
     RelayHKVEG1_192.168.3.10_33524:
       BUF       
       EXPECT     idle
       IODev      RelayHKVEG1_192.168.3.10_33524
       MODBUSID   57
       NAME       RelayHKVEG1_192.168.3.10_33524
       NR         160
       PEER       192.168.3.10
       PORT       33524
       RELAY      HKVEG1
       RELID      7
       SNAME      RelayHKVEG1
       SSL       
       STATE      disconnected
       TCPChild   1
       TCPConn    1
       TEMPORARY  1
       TYPE       ModbusAttr
       CHANGED:
         disconnected
       CHANGEDWITHSTATE:
       CHILDOF:
       FRAME:
       READ:
         BUFFER     
       READINGS:
         2019-10-08 06:30:29   state           disconnected
       REMEMBER:
         lid        57
         lname      RelayHKVEG1_192.168.3.10_33524
         lrecv      1570508928.66522
         lsend      1570508928.67016
       REQUEST:
         ADR        2
         FCODE      1
         LEN        1
         MODBUSID   57
         PDU       


         TID        144
         TYPE       c
         DEVHASH:
     RelayHKVEG1_192.168.3.10_33872:
       BUF       
       EXPECT     request
       FD         27
       IODev      RelayHKVEG1_192.168.3.10_33872
       MODBUSID   57
       NAME       RelayHKVEG1_192.168.3.10_33872
       NR         4277
       PEER       192.168.3.10
       PORT       33872
       RELAY      HKVEG1
       RELID      7
       SNAME      RelayHKVEG1
       SSL       
       STATE      Connected
       TCPChild   1
       TCPConn    1
       TEMPORARY  1
       TYPE       ModbusAttr
       CHILDOF:
       READ:
         BUFFER     
       READINGS:
         2019-10-09 07:50:48   state           Connected
       REMEMBER:
         lid        57
         lname      RelayHKVEG1_192.168.3.10_33872
         lrecv      1570600379.58042
         lsend      1570600379.56862
       REQUEST:
         ADR        4
         FCODE      1
         LEN        1
         MODBUSID   57
         PDU       


         TID        178
         TYPE       c
         DEVHASH:
     RelayHKVEG1_192.168.3.10_33894:
       BUF       
       EXPECT     request
       FD         33
       IODev      RelayHKVEG1_192.168.3.10_33894
       MODBUSID   57
       NAME       RelayHKVEG1_192.168.3.10_33894
       NR         4287
       PEER       192.168.3.10
       PORT       33894
       RELAY      HKVEG1
       RELID      7
       SNAME      RelayHKVEG1
       SSL       
       STATE      Connected
       TCPChild   1
       TCPConn    1
       TEMPORARY  1
       TYPE       ModbusAttr
       CHILDOF:
       READ:
         BUFFER     
       READINGS:
         2019-10-09 07:52:42   state           Connected
       REMEMBER:
         lid        57
         lname      RelayHKVEG1_192.168.3.10_33894
         lrecv      1570601024.47478
         lsend      1570601024.46291
       REQUEST:
         ADR        3
         FCODE      1
         LEN        1
         MODBUSID   57
         PDU       


         TID        124
         TYPE       c
         DEVHASH:
     RelayHKVEG1_192.168.3.10_34014:
       BUF       
       EXPECT     request
       FD         17
       IODev      RelayHKVEG1_192.168.3.10_34014
       MODBUSID   57
       NAME       RelayHKVEG1_192.168.3.10_34014
       NR         4331
       PEER       192.168.3.10
       PORT       34014
       RELAY      HKVEG1
       RELID      7
       SNAME      RelayHKVEG1
       SSL       
       STATE      Connected
       TCPChild   1
       TCPConn    1
       TEMPORARY  1
       TYPE       ModbusAttr
       CHILDOF:
       READ:
         BUFFER     
       READINGS:
         2019-10-09 08:03:32   state           Connected
       REMEMBER:
         lid        57
         lname      RelayHKVEG1_192.168.3.10_34014
         lrecv      1570646600.46573
         lsend      1570646600.45299
       REQUEST:
         ADR        13
         FCODE      4
         LEN        1
         MODBUSID   57
         PDU        


         TID        68
         TYPE       i
         DEVHASH:
     RelayHKVEG1_192.168.3.10_40612:
       BUF       
       EXPECT     request
       FD         34
       IODev      RelayHKVEG1_192.168.3.10_40612
       MODBUSID   57
       NAME       RelayHKVEG1_192.168.3.10_40612
       NR         5537
       PEER       192.168.3.10
       PORT       40612
       RELAY      HKVEG1
       RELID      7
       SNAME      RelayHKVEG1
       SSL       
       STATE      Connected
       TCPChild   1
       TCPConn    1
       TEMPORARY  1
       TYPE       ModbusAttr
       CHILDOF:
       FRAME:
       READ:
         BUFFER     
       READINGS:
         2019-10-09 20:43:02   state           Connected
       REMEMBER:
         lid        57
         lname      RelayHKVEG1_192.168.3.10_40612
         lrecv      1570647306.14011
         lsend      1570647306.14516
       REQUEST:
         ADR        7
         FCODE      1
         LEN        1
         MODBUSID   57
         PDU       


         TID        102
         TYPE       c
         DEVHASH:
     RelayHKVEG1_192.168.3.10_40724:
       BUF       
       EXPECT     request
       FD         16
       IODev      RelayHKVEG1_192.168.3.10_40724
       MODBUSID   57
       MODE       relay
       NAME       RelayHKVEG1_192.168.3.10_40724
       NR         5587
       PEER       192.168.3.10
       PORT       40724
       PROTOCOL   TCP
       RELAY      HKVEG1
       RELID      7
       SNAME      RelayHKVEG1
       SSL       
       STATE      Connected
       TCPChild   1
       TCPConn    1
       TEMPORARY  1
       TYPE       ModbusAttr
       CHILDOF:
       READ:
         BUFFER     
       READINGS:
         2019-10-09 20:55:06   state           Connected
       REMEMBER:
         lid        57
         lname      RelayHKVEG1_192.168.3.10_40724
         lrecv      1570651032.73492
         lsend      1570651032.34768
       REQUEST:
         ADR        4
         FCODE      1
         LEN        1
         MODBUSID   57
         PDU       


         TID        243
         TYPE       c
         DEVHASH:
     RelayHKVEG1_192.168.3.10_46176:
       BUF       
       EXPECT     request
       FD         18
       IODev      RelayHKVEG1_192.168.3.10_46176
       MODBUSID   57
       NAME       RelayHKVEG1_192.168.3.10_46176
       NR         1835
       PEER       192.168.3.10
       PORT       46176
       RELAY      HKVEG1
       SNAME      RelayHKVEG1
       SSL       
       STATE      Connected
       TCPChild   1
       TCPConn    1
       TEMPORARY  1
       TYPE       ModbusAttr
       CHILDOF:
       READINGS:
         2019-10-08 06:30:29   state           Connected
     RelayHKVEG1_192.168.3.10_46206:
       BUF       
       EXPECT     request
       FD         25
       IODev      RelayHKVEG1_192.168.3.10_46206
       MODBUSID   57
       NAME       RelayHKVEG1_192.168.3.10_46206
       NR         1845
       PEER       192.168.3.10
       PORT       46206
       RELAY      HKVEG1
       RELID      7
       SNAME      RelayHKVEG1
       SSL       
       STATE      Connected
       TCPChild   1
       TCPConn    1
       TEMPORARY  1
       TYPE       ModbusAttr
       CHILDOF:
       FRAME:
       READ:
         BUFFER     
       READINGS:
         2019-10-08 06:32:07   state           Connected
       REMEMBER:
         lid        57
         lname      RelayHKVEG1_192.168.3.10_46206
         lrecv      1570512955.83844
         lsend      1570512955.82821
       REQUEST:
         ADR        18
         FCODE      1
         LEN        1
         MODBUSID   57
         PDU       


         TID        50
         TYPE       c
         DEVHASH:
     RelayHKVEG1_192.168.3.10_46910:
       BUF       
       EXPECT     request
       FD         29
       IODev      RelayHKVEG1_192.168.3.10_46910
       MODBUSID   57
       NAME       RelayHKVEG1_192.168.3.10_46910
       NR         1970
       PEER       192.168.3.10
       PORT       46910
       RELAY      HKVEG1
       SNAME      RelayHKVEG1
       SSL       
       STATE      Connected
       TCPChild   1
       TCPConn    1
       TEMPORARY  1
       TYPE       ModbusAttr
       CHILDOF:
       READ:
         BUFFER     
       READINGS:
         2019-10-08 07:35:56   state           Connected
       REMEMBER:
         lid        57
         lname      RelayHKVEG1_192.168.3.10_46910
         lrecv      1570600248.22052
         lsend      1570600248.223
       REQUEST:
         ADR        3
         ERRCODE    10
         FCODE      1
         LEN        1
         MODBUSID   57
         PDU       


         TID        192
         TYPE       c
         DEVHASH:
   READ:
     BUFFER     
   READINGS:
     2019-10-07 10:00:12   state           opened
   REMEMBER:
     lsend      1570651031.11842
   defptr:
     RelayHKVEG1 57
   gotReadings:
Attributes:
   room       Modbus

auffallend: 9 *neun* connections , obwohl ja nur eine besteht ..

MBGate, HKVEG1 und Relay HKVEG1 waren für das Log auf verbose 5 eingestellt.

Die Logs hab ich mal auf 10 Minuten gekürzt ab dem Zeitpunkt als sich der Client verbindet und auch noch gepackt, weil dennoch zu groß .

Ich bin gespannt, was Stefan in den Logs findet  

Grüße
Mike

[StefanStrobel]

Hallo Mike,

Vielen Dank für die ausführlichen Logs.
Nur um zu verhindern, dass ich an den falschen Stellen suche:
Welches sind denn die unsinnigen Werte?

Gruß
    Stefan

[Mike73]

Guten Morgen Stefan,

ich habe jetzt das Log durchsucht, um dir ein Beispiel für einen Fehler zu geben. Da ist keiner drin 

Da stellt sich die Frage WARUM?  - Das Log ist unter "Laborbedingungen" entstanden. Ich hatte alle anderen Relays disabled.

Vermutlich hat es also etwas mit der parallelen Nutzung mehrer Relays zu tun. Nachdem ich das für ZContr wieder aktiviert habe, sieht das Log am Client ( verbose 3, Filter .*Modbus.*  ) auszugsweise so aus:

Code Auswählen Erweitern


2019-10-10 07:36:25 ModbusAttr ZContr 1W-DevCount: 15
2019.10.10 07:36:26 3 : HKVEG1: Timeout waiting for a modbus response request: id 57, fCode 1, tid 24, type c, adr 3, len 1 for device HKVEG1 reading HK5 (getUpdate), queued 13.82 secs ago, sent 3.00 secs ago, read buffer empty
2019.10.10 07:36:27 3 : ZContr: Timeout waiting for a modbus response request: id 56, fCode 3, tid 149, type h, adr 41001, len 1 for device ZContr reading 1W-ROM-1 (getUpdate), queued 15.07 secs ago, sent 2.00 secs ago, read buffer empty
2019.10.10 07:36:31 3 : ZContr: Timeout waiting for a modbus response request: id 56, fCode 4, tid 237, type i, adr 30001, len 1 for device ZContr reading 1W-VAL-1 (getUpdate), queued 9.41 secs ago, sent 2.00 secs ago, read buffer empty
2019-10-10 07:36:34 ModbusAttr ZContr LaufZeit: 65064
2019.10.10 07:36:36 3 : ZContr: Timeout waiting for a modbus response request: id 56, fCode 1, tid 87, type c, adr 0008, len 1 for device ZContr reading ZTrigger (getUpdate), queued 14.09 secs ago, sent 2.00 secs ago, read buffer empty
2019-10-10 07:36:36 ModbusAttr HKVEG1 HK6: off
2019.10.10 07:36:41 3 : ZContr: Timeout waiting for a modbus response request: id 56, fCode 4, tid 59, type i, adr 30001, len 1 for device ZContr reading 1W-VAL-1 (getUpdate), queued 8.79 secs ago, sent 2.00 secs ago, read buffer empty
2019.10.10 07:36:42 3 : HKVEG1: Timeout waiting for a modbus response request: id 57, fCode 1, tid 38, type c, adr 2, len 1 for device HKVEG1 reading HK4 (getUpdate), queued 19.73 secs ago, sent 3.00 secs ago, read buffer empty
2019.10.10 07:36:43 3 : ZContr: Timeout waiting for a modbus response request: id 56, fCode 2, tid 62, type d, adr 0003, len 1 for device ZContr reading runF (getUpdate), queued 10.79 secs ago, sent 2.00 secs ago, read buffer empty
2019-10-10 07:36:43 ModbusAttr ZContr LaufZeit: 1
2019.10.10 07:36:46 3 : HKVEG1: Timeout waiting for a modbus response request: id 57, fCode 1, tid 7, type c, adr 4, len 1 for device HKVEG1 reading HK6 (getUpdate), queued 14.60 secs ago, sent 3.00 secs ago, read buffer empty
2019.10.10 07:36:47 3 : ZContr: Timeout waiting for a modbus response request: id 56, fCode 3, tid 16, type h, adr 41001, len 1 for device ZContr reading 1W-ROM-1 (getUpdate), queued 15.60 secs ago, sent 2.00 secs ago, read buffer empty
2019.10.10 07:36:47 3 : ZContr: read got new data while idle, drop buffer 0010000000053804020066
2019.10.10 07:36:47 3 : HKVEG1: read got new data while idle, drop buffer 00190000000439010100
2019.10.10 07:36:47 3 : ZContr: read got new data while idle, drop buffer 00100000000438020101
2019-10-10 07:36:50 ModbusAttr ZContr SperrZeit: 10
2019.10.10 07:36:51 3 : HKVEG1: Timeout waiting for a modbus response request: id 57, fCode 1, tid 241, type c, adr 6, len 1 for device HKVEG1 reading HK8 (getUpdate), queued 19.24 secs ago, sent 3.00 secs ago, read buffer empty
2019.10.10 07:36:52 3 : ZContr: Timeout waiting for a modbus response request: id 56, fCode 4, tid 132, type i, adr 30200, len 1 for device ZContr reading NTCVAL (getUpdate), queued 9.92 secs ago, sent 2.00 secs ago, read buffer empty
2019.10.10 07:36:54 3 : ZContr: Timeout waiting for a modbus response request: id 56, fCode 3, tid 254, type h, adr 40001, len 1 for device ZContr reading LaufZeit (getUpdate), queued 12.15 secs ago, sent 2.00 secs ago, read buffer empty
2019-10-10 07:36:57 ModbusAttr HKVEG1 HK5 on
2019-10-10 07:36:57 ModbusAttr HKVEG1 HK6 on
2019-10-10 07:36:59 ModbusAttr HKVEG1 HK6: on
2019.10.10 07:37:01 3 : ZContr: Timeout waiting for a modbus response request: id 56, fCode 4, tid 250, type i, adr 30001, len 1 for device ZContr reading 1W-VAL-1 (getUpdate), queued 9.25 secs ago, sent 2.00 secs ago, read buffer empty
2019.10.10 07:37:03 3 : ZContr: Timeout waiting for a modbus response request: id 56, fCode 1, tid 95, type c, adr 0008, len 1 for device ZContr reading ZTrigger (getUpdate), queued 11.53 secs ago, sent 2.00 secs ago, read buffer empty
2019-10-10 07:37:04 ModbusAttr Fronius1 F_Site_Total: 4
2019-10-10 07:37:04 ModbusAttr ZContr 1W-DevCount: 65064



Da sind zunächst wieder die Timeouts, dann die Meldungen wie

Code Auswählen Erweitern

"ZContr: read got new data while idle, drop buffer 0010000000053804020066"

und auch "unsinnige" Werte wie

Code Auswählen Erweitern


2019-10-10 07:36:25 ModbusAttr ZContr 1W-DevCount: 15
.
.
2019-10-10 07:37:04 ModbusAttr ZContr 1W-DevCount: 65064
, was real nur ein Device ist .

Soll ich da jetzt nochmal unter diesen Bedingungen so ein umfangreicheres Log machen oder noch etwas anderes testen?

Gruß
Mike

[StefanStrobel]

Hallo Mike,

Wir kommen der Sache näher
Es ist vermutlich ein Problem, das nur bei mehreren Relays auftritt.
Um das besser nachvollziehen zu können, könntest Du mir noch genauer beschreiben, welche Geräte wie miteinander reden?
Sind das mehrere Geräte an einem gemeinsamen RS485-Bus, die von mehreren Relay-Definitionen in einem gemeinsamen Fhem per TCP an einen Client bereitgestellt werden?
Oder sind da mehr als 2 Fhem-Installationen beteiligt?

Gruß / Thanx
    Stefan

[Mike73]

Hallo Stefan,

Um das besser nachvollziehen zu können, könntest Du mir noch genauer beschreiben, welche Geräte wie miteinander reden?

Also ... es gibt EINEN RS485-Bus mit aktuell drei Modbus-Geräten: Heizkreisverteiler (HKVEG1) , Zirkulationskontrolle (ZContr) sowie den Solarwechselrichter (Fronius1) . Dieser Bus wird von einer FHEM-Instanz (FHEM1) über das Device MBGate abgefragt (und beschrieben). Auf einer zweiten FHEM-Instanz im Netz (FHEM2) werden aktuell der HKVEG1 und der Fronius1 ( und bisher auch das ZContr) verwendet. FHEM1 diente also bisher ausschließlich als Relay für diese drei Geräte.

Hier mal die Definitionen

MBGate:

Code Auswählen Erweitern


define:
defmod MBGate Modbus /dev/ttyUSB0@19200
attr MBGate room Modbus
attr MBGate timeoutLogLevel 4

list::
Internals:
   DEF        /dev/ttyUSB0@19200
   DeviceName /dev/ttyUSB0@19200
   EXPECT     response
   FD         10
   FUUID      5c7596dd-f33f-53e7-2a57-81c950e0f8764b0b
   LASTOPEN   1570719741.89892
   MODE       master
   NAME       MBGate
   NR         131
   NTFY_ORDER 50-MBGate
   PARTIAL   
   PROTOCOL   RTU
   STATE      opened
   SerialConn 1
   TYPE       Modbus
   devioLoglevel 3
   nextOpenDelay 60
   nextQueueRun 1570730796.81963
   nextTimeout 1570730796.81415
   FRAME:
   QUEUE:
     HASH(0x8fd4a90)
     HASH(0xaa79138)
     HASH(0xaa64b88)
     HASH(0xaa6a0c0)
     HASH(0xaa676f0)
     HASH(0xa9d12c8)
     HASH(0xaa77780)
     HASH(0xaa68bd8)
     HASH(0xaa65f80)
     HASH(0xa9ca608)
     HASH(0xaa75ab8)
     HASH(0x8fb4118)
     HASH(0xaa64488)
     HASH(0xaa07f38)
     HASH(0xaa6ab68)
     HASH(0xa9cd058)
     HASH(0x8fb46d8)
     HASH(0x8e1ad10)
     HASH(0xa9d3d80)
     HASH(0xa9ccbe8)
     HASH(0xaa6c7c0)
     HASH(0xaa755b8)
     HASH(0xaa07358)
     HASH(0xaa78f98)
   READ:
     BUFFER     
   READINGS:
     2019-10-10 17:02:21   state           opened
   REMEMBER:
     lid        1
     lname      MBGate
     lrecv      1570730788.79952
     lsend      1570730794.81717
   REQUEST:
     ADR        502
     DBGINFO    getUpdate
     FCODE      3
     FRAME     

���
     LEN        4
     MODBUSID   1
     OPERATION  read
     READING    F_Site_Energy_Day
     SENT       1570730794.81415
     TIMESTAMP  1570730777.77799
     TYPE       h
     VALUES     0
     DEVHASH:
       CHANGED   
       DEF        1 10
       FUUID      5c759eec-f33f-53e7-810b-f27ff2e2548329a1
       INTERVAL   10
       IODev      MBGate
       MODBUSID   1
       MODE       master
       MODULEVERSION Modbus 4.1.5 - 17.9.2019
       NAME       Fronius1
       NOTIFYDEV  global
       NR         135
       NTFY_ORDER 50-Fronius1
       PROTOCOL   RTU
       STATE      opened
       TRIGGERTIME 1570730797.76961
       TRIGGERTIME_FMT 2019-10-10 20:06:37
       TYPE       ModbusAttr
       lastUpdate 1570730787.76961
       FRAME:
       READ:
       READINGS:
         2019-10-10 19:21:40   F_Active_State_Code 0
         2019-10-10 19:21:49   F_ModelType     0
         2019-10-10 19:21:40   F_Site_Energy_Day 12312
         2019-10-10 19:21:39   F_Site_Energy_Year 103
         2019-10-10 19:21:39   F_Site_Power    0
         2019-10-10 18:13:36   F_Site_Total    3378643255
         2019-10-10 18:15:14   state           opened
       REMEMBER:
         lrecv      1570728109.25355
         lsend      1570730794.81717
       gotReadings:
         F_ModelType 0
       lastRead:
         h213       1570722994.71628
         h214       1570728100.54474
         h216       1570728109.25644
         h499       1570723234.48913
         h500       1570728099.89025
         h501       1570723274.80587
         h502       1570728100.21757
         h505       1570723285.80048
         h506       1570728099.55056
         h509       1570723333.85567
         h510       1570724016.29744
   defptr:
     Fronius1   1
     HKVEG1     7
     ZContr     6
Attributes:
   room       Modbus
   timeoutLogLevel 4


HKVEG1 und das Relay

Code Auswählen Erweitern


defmod HKVEG1 ModbusAttr 7 0
attr HKVEG1 room Modbus

Internals:
   CHANGED   
   DEF        7 0
   FUUID      5d9d77bd-f33f-53e7-8e15-3e37ba56d40b0bad
   IODev      MBGate
   MODBUSID   7
   MODE       master
   MODULEVERSION Modbus 4.1.5 - 17.9.2019
   NAME       HKVEG1
   NOTIFYDEV  global
   NR         143
   NTFY_ORDER 50-HKVEG1
   PROTOCOL   RTU
   STATE      opened
   TYPE       ModbusAttr
   READINGS:
     2019-10-10 16:59:49   state           opened
   gotReadings:
Attributes:
   room       Modbus


defmod RelayHKVEG1 ModbusAttr 57 relay 192.168.3.15:1502 TCP to HKVEG1
attr RelayHKVEG1 room Modbus

Internals:
   CHANGED   
   CONNECTS   1
   DEF        57 relay 192.168.3.15:1502 TCP to HKVEG1
   DeviceName 192.168.3.15:1502
   EXPECT     request
   FD         11
   FUUID      5c759876-f33f-53e7-e63d-dbf32ea83003afce
   IODev      RelayHKVEG1
   LASTCONN   RelayHKVEG1_192.168.3.10_52534
   MODBUSID   57
   MODE       relay
   MODULEVERSION Modbus 4.1.5 - 17.9.2019
   NAME       RelayHKVEG1
   NOTIFYDEV  global
   NR         132
   NTFY_ORDER 50-RelayHKVEG1
   PORT       1502
   PROTOCOL   TCP
   RELAY      HKVEG1
   RELID      7
   STATE      opened
   TCPConn    1
   TCPServer  1
   TYPE       ModbusAttr
   CONNECTHASH:
     RelayHKVEG1_192.168.3.10_52534:
       BUF       
       EXPECT     request
       FD         21
       IODev      RelayHKVEG1_192.168.3.10_52534
       MODBUSID   57
       MODE       relay
       NAME       RelayHKVEG1_192.168.3.10_52534
       NR         152
       PEER       192.168.3.10
       PORT       52534
       PROTOCOL   TCP
       RELAY      HKVEG1
       RELID      7
       SNAME      RelayHKVEG1
       SSL       
       STATE      Connected
       TCPChild   1
       TCPConn    1
       TEMPORARY  1
       TYPE       ModbusAttr
       CHILDOF:
       READ:
         BUFFER     
       READINGS:
         2019-10-10 17:00:23   state           Connected
       REMEMBER:
         lid        57
         lname      RelayHKVEG1_192.168.3.10_52534
         lrecv      1570731004.88455
         lsend      1570730998.72505
       REQUEST:
         ADR        4
         FCODE      5
         LEN        1
         MODBUSID   57
         PDU        
         TID        236
         TYPE       c
         VALUES     
         DEVHASH:
   READ:
     BUFFER     
   READINGS:
     2019-10-10 16:59:49   state           opened
   REMEMBER:
     lsend      1570730981.44594
   defptr:
     RelayHKVEG1 57
   gotReadings:
Attributes:
   room       Modbus



und der Fronius

Code Auswählen Erweitern


defmod Fronius1 ModbusAttr 1 10
attr Fronius1 event-min-interval .*:300
attr Fronius1 event-on-change-reading .*
attr Fronius1 room Modbus
attr Fronius1 verbose 3

Internals:
   DEF        1 10
   FUUID      5d9f74d9-f33f-53e7-505f-bfb915bd8518f9d5
   INTERVAL   10
   IODev      MBGate
   MODBUSID   1
   MODE       master
   MODULEVERSION Modbus 4.1.5 - 17.9.2019
   NAME       Fronius1
   NOTIFYDEV  global
   NR         859
   NTFY_ORDER 50-Fronius1
   PROTOCOL   RTU
   STATE      opened
   TRIGGERTIME 1570731277.90637
   TRIGGERTIME_FMT 2019-10-10 20:14:37
   TYPE       ModbusAttr
   lastUpdate 1570731267.90637
   READINGS:
     2019-10-10 20:13:45   state           opened
Attributes:
   event-min-interval .*:300
   event-on-change-reading .*
   room       Modbus
   verbose    3

defmod RelayFronius1 ModbusAttr 51 relay 192.168.3.15:1504 TCP to Fronius1
attr RelayFronius1 room Modbus

Internals:
   CONNECTS   2
   DEF        51 relay 192.168.3.15:1504 TCP to Fronius1
   DeviceName 192.168.3.15:1504
   EXPECT     request
   FD         15
   FUUID      5c759f0e-f33f-53e7-e08d-5681be80c05b6f39
   IODev      RelayFronius1
   LASTCONN   RelayFronius1_192.168.3.10_35926
   MODBUSID   51
   MODE       relay
   MODULEVERSION Modbus 4.1.5 - 17.9.2019
   NAME       RelayFronius1
   NOTIFYDEV  global
   NR         136
   NTFY_ORDER 50-RelayFronius1
   PORT       1504
   PROTOCOL   TCP
   RELAY      Fronius1
   STATE      opened
   TCPConn    1
   TCPServer  1
   TYPE       ModbusAttr
   READ:
     BUFFER     
   READINGS:
     2019-10-10 20:14:58   state           opened
   REMEMBER:
     lsend      1570724010.64428
   defptr:
     RelayFronius1 51
   gotReadings:
Attributes:
   room       Modbus


Dazu die Devices auf dem FHEM2:

HKVEG1

Code Auswählen Erweitern


Internals:
   CHANGED   
   DEF        57 10 192.168.3.15:1502 TCP
   DeviceName 192.168.3.15:1502
   EXPECT     response
   FD         31
   FUUID      5c5da6c9-f33f-53e7-4c38-f79a22e8f0185b2c
   INTERVAL   10
   IODev      HKVEG1
   LASTOPEN   1570719623.38817
   MODBUSID   57
   MODE       master
   MODULEVERSION Modbus 4.1.5 - 17.9.2019
   NAME       HKVEG1
   NOTIFYDEV  global
   NR         35
   NTFY_ORDER 50-HKVEG1
   PARTIAL   
   PROTOCOL   TCP
   STATE      opened
   TCPConn    1
   TRIGGERTIME 1570731469.70685
   TRIGGERTIME_FMT 2019-10-10 20:17:49
   TRIGGERTIME_SAVED
   TYPE       ModbusAttr
   devioLoglevel 3
   lastUpdate 1570731459.70685
   nextOpenDelay 60
   nextQueueRun 1570731464.75762
   nextTimeout 1570731466.75491
   FRAME:
   Helper:
     DBLOG:
       1W-val-1:
         logdb:
           TIME       1570728129.7915
           VALUE      33.5
   QUEUE:
     HASH(0x482cc50)
     HASH(0x483a5b8)
     HASH(0x48309c8)
     HASH(0x48203f0)
     HASH(0x48302d8)
     HASH(0x482ca28)
   READ:
     BUFFER     
   READINGS:
     2019-10-10 20:17:40   1W-val-1        33.5
     2019-10-10 20:17:37   1WConvertT      0
     2019-10-10 20:17:37   1WScanBus       0
     2019-10-10 20:17:36   1Wcount         1
     2019-10-10 20:17:35   HK-ALL-OFF      0
     2019-10-10 20:17:42   HK-ALL-ON       0
     2019-10-10 20:17:38   HK1             off
     2019-10-10 20:17:36   HK2             off
     2019-10-10 20:17:38   HK3             off
     2019-10-10 20:17:41   HK4             off
     2019-10-10 20:17:39   HK5             off
     2019-10-10 20:17:40   HK6             off
     2019-10-10 20:17:43   HK7             off
     2019-10-10 20:17:41   HK8             off
     2019-10-10 20:17:42   HK9             off
     2019-10-10 17:00:23   state           opened
   REMEMBER:
     lid        57
     lname      HKVEG1
     lrecv      1570731463.37003
     lsend      1570731463.75727
   REQUEST:
     ADR        19
     DBGINFO    getUpdate
     FCODE      1
     FRAME      �9


     LEN        1
     MODBUSID   57
     OPERATION  read
     READING    HK-ALL-OFF
     SENT       1570731463.75491
     TID        223
     TIMESTAMP  1570731459.72489
     TYPE       c
     VALUES     0
     DEVHASH:
   defptr:
     HKVEG1     57
   gotReadings:
     HK7        off
   lastRead:
     c0         1570731456.07442
     c1         1570731458.09085
     c16        1570731457.58744
     c17        1570731457.08421
     c18        1570731462.36141
     c19        1570731455.57076
     c2         1570731461.3516
     c3         1570731459.83872
     c4         1570731460.34442
     c5         1570731463.37142
     c6         1570731461.85765
     c7         1570731462.87062
     c8         1570731458.59398
     i0         1570731456.58094
     i13        1570731460.85252
Attributes:
   DbLogInclude 1W-val-.*
   dev-c-defPoll 1
   dev-i-defPoll 1
   dev-timing-sendDelay 0.5
   dev-timing-timeout 3
   event-on-change-reading .*
   obj-c0-map 0:off,1:on
   obj-c0-reading HK2
   obj-c0-set 1
   obj-c1-map 0:off,1:on
   obj-c1-reading HK3
   obj-c1-set 1
   obj-c16-reading 1WConvertT
   obj-c16-set 1
   obj-c17-reading 1WScanBus
   obj-c17-set 1
   obj-c18-reading HK-ALL-ON
   obj-c18-set 1
   obj-c19-reading HK-ALL-OFF
   obj-c19-set 1
   obj-c2-map 0:off,1:on
   obj-c2-reading HK4
   obj-c2-set 1
   obj-c3-map 0:off,1:on
   obj-c3-reading HK5
   obj-c3-set 1
   obj-c4-map 0:off,1:on
   obj-c4-reading HK6
   obj-c4-set 1
   obj-c5-map 0:off,1:on
   obj-c5-reading HK7
   obj-c5-set 1
   obj-c6-map 0:off,1:on
   obj-c6-reading HK8
   obj-c6-set 1
   obj-c7-map 0:off,1:on
   obj-c7-reading HK9
   obj-c7-set 1
   obj-c8-map 0:off,1:on
   obj-c8-reading HK1
   obj-c8-set 1
   obj-c9-map 0:off,1:on
   obj-i0-expr ($val >> 8 )
   obj-i0-reading 1Wcount
   obj-i13-expr ( $val / 2 )
   obj-i13-format %.1f
   obj-i13-poll 1
   obj-i13-reading 1W-val-1
   room       Modbus
   userattr   DbLogInclude dev-c-combine dev-c-defPoll dev-h-combine dev-i-defPoll disable enableControlSet event-on-change-reading obj-c0-map obj-c0-reading obj-c0-set obj-c1-map obj-c1-reading obj-c1-set obj-c16-reading obj-c16-set obj-c17-reading obj-c17-set obj-c18-reading obj-c18-set obj-c19-reading obj-c19-set obj-c2-map obj-c2-reading obj-c2-set obj-c3-map obj-c3-reading obj-c3-set obj-c4-map obj-c4-reading obj-c4-set obj-c5-map obj-c5-reading obj-c5-set obj-c6-map obj-c6-reading obj-c6-set obj-c7-map obj-c7-reading obj-c7-set obj-c8-map obj-c8-reading obj-c8-set obj-c9-map obj-h0-reading obj-h1-reading obj-i0-expr obj-i0-reading obj-i13-expr obj-i13-format obj-i13-poll obj-i13-reading openTimeout verbose
   verbose    3


und Fronius

Code Auswählen Erweitern


Internals:
   DEF        51 10 192.168.3.15:1504 TCP
   DeviceName 192.168.3.15:1504
   EXPECT     idle
   FUUID      5c5da6c9-f33f-53e7-1a86-ef80cbf91187f7f3
   INTERVAL   10
   IODev      Fronius1
   LASTOPEN   1570731527.75132
   MODBUSID   51
   MODE       master
   MODULEVERSION Modbus 4.1.5 - 17.9.2019
   NAME       Fronius1
   NEXT_OPEN  1570732119
   NOTIFYDEV  global
   NR         30
   NTFY_ORDER 50-Fronius1
   PARTIAL   
   PROTOCOL   TCP
   STATE      disconnected
   TCPConn    1
   TIMEOUTS   1
   TRIGGERTIME 1570731529.70599
   TRIGGERTIME_FMT 2019-10-10 20:18:49
   TYPE       ModbusAttr
   devioLoglevel 3
   lastUpdate 1570731519.70599
   nextOpenDelay 900
   FRAME:
     DATA       0
     FCODE      3
     MODBUSID   51
     PDULEXP    10
     TID        15
   Helper:
     DBLOG:
       F_Site_Energy_Day:
         logdb:
           TIME       1570723942.74183
           VALUE      12302
       F_Site_Energy_Year:
         logdb:
           TIME       1570723949.30168
           VALUE      20433240
       F_Site_Power:
         logdb:
           TIME       1570723872.55345
           VALUE      0
       F_Site_Total:
         logdb:
           TIME       1570724010.99301
           VALUE      12303
   QUEUE:
     HASH(0x483d1c8)
     HASH(0x4840e28)
     HASH(0x4823050)
     HASH(0x132c960)
     HASH(0x48378d8)
     HASH(0x4834098)
     HASH(0x482ca10)
     HASH(0x1508280)
     HASH(0x4834920)
     HASH(0x15380e0)
   READ:
     BUFFER     
   READINGS:
     2019-10-10 18:13:20   F_Active_State_Code 0
     2019-10-10 18:12:22   F_Site_Energy_Day 12302
     2019-10-10 18:12:29   F_Site_Energy_Year 20433240
     2019-10-10 18:13:15   F_Site_Power    0
     2019-10-10 18:13:30   F_Site_Total    12303
     2019-10-10 20:13:39   state           disconnected
   REMEMBER:
     lid        51
     lname      Fronius1
     lrecv      1570724016.97228
     lsend      1570724013.32811
   defptr:
     Fronius1   51
   gotReadings:
   lastRead:
     h213       1570724000.57744
     h499       1570723995.27645
     h501       1570723942.74024
     h505       1570723949.29998
     h509       1570724010.99143
Attributes:
   DbLogInclude F_Site_Energy_Day,F_Site_Energy_Year,F_Site_Power,F_Site_Total
   dev-h-defPoll 1
   disable    0
   enableControlSet 0
   event-min-interval .*:300
   event-on-change-reading .*
   nextOpenDelay 900
   obj-h213-reading F_Active_State_Code
   obj-h499-len 2
   obj-h499-reading F_Site_Power
   obj-h499-unpack L>
   obj-h501-len 4
   obj-h501-reading F_Site_Energy_Day
   obj-h501-unpack Q>
   obj-h505-len 4
   obj-h505-reading F_Site_Energy_Year
   obj-h505-unpack Q>
   obj-h509-len 4
   obj-h509-reading F_Site_Total
   obj-h509-unpack Q>
   room       SWR
   userattr   DbLogInclude dev-h-defPoll enableControlSet event-min-interval event-on-change-reading nextOpenDelay obj-h213-reading obj-h499-len obj-h499-reading obj-h499-revRegs obj-h499-unpack obj-h501-format obj-h501-len obj-h501-reading obj-h501-revRegs obj-h501-unpack obj-h505-len obj-h505-reading obj-h505-unpack obj-h509-len obj-h509-reading obj-h509-revRegs obj-h509-unpack obj-h510-unpack


Soviel zur Situation . Den ZContr hab ich jetzt ausgelassen.

PlanB wäre , nur den HKV via Relay auf FHEM2 zu behalten und die anderen beiden auf dem FHEM1 direkt zu konfigurieren. Das könnte _mein_ Problem dann wohl lösen, nicht aber den Grund beseitigen   

Gruß
Mike

[StefanStrobel]

Hallo Mike,

vielen Dank für die Details.
Ein Fehler, der ja nun schon klar ist, ist dass ein Relay zwischen TCP und RS485 auf seiner RS485-Seite ein Problem hat,
wenn gleichzeitig ein zweiter Update-Timer lokal auf der "Master"-Seite des Relays läuft.

Das Problem muss ich im Modul lösen bzw. verhindern, dass so ein zweiter Timer definiert wird.

Für HKVEG1 hast Du den Timer ja abgeschaltet, aber für Fronius1 steht er noch auf 10 Sekunden.
bevor wir nach weiteren Problemen suchen, würde ich Dich bitten, auch bei Fronius1 auf Fhem1 den lokalen Timer auf 0 zu setzen.

Wenn es danach immer noch Probleme gibt, dann bräuchte ich nochmal ein so ausführliches Log wie beim letzten Mal.
Damit sollte ich dann eventuelle weitere Probleme im Modul eingrenzen und beheben können.

Gruss / Thanx
    Stefan

[Mike73]

Moin Stefan,

ich hab jetzt folgendes gemacht:
FHEM2: Fronius und ZContr deaktiviert , nur HKVEG1 läuft noch via Relay
FHEM1: Fronius komplett deaktiviert , HKVEG1 Master ohne eigenen Timer,
             ZContr von FHEM2 auf 1 umgezogen, der läuft jetzt nur hier lokal.

Jetzt scheint es auf den ersten Blick gut zu laufen. Letztlich brachte erst das Deaktivieren des zweiten Relays ( für den Fronius ) den gewünschten Effekt. Solange das Relay (mehr als eins) aktiv war, auch ohne eigenen Update-Timer des "Master"-Devices, lief es nicht sauber.

So kann ich es auch erstmal lassen. WFM ( works for me  )   

viele Grüße und schönen Freitag !
Mike 

[StefanStrobel]

Hallo Mike,

auch wenn das Setup mit mehreren Relays nicht alltäglich ist, würde ich das Problem doch gerne lösen bzw. die Bugs im Modul für so ein Setup beheben.
Ich versuche mal das ganze bei mir nachzubauen. Falls Du nochmal Zeit findest, Logs wie beschrieben zu erzeugen, wäre das natürlich eine große Hilfe

Gruss / Thanx
    Stefan

[oniT]

Hallo Stefan,

ich habe noch einen offenen Punkt aus dem alten Thread. Jetzt nach Jahren komme ich endlich dazu an dem Projekt weiter zu machen.

Ich habe das Problem, dass die Werte nicht geschrieben werden. Die PDF mit den Registern ist angehängt. Der Auszug aus der Config, für das Modbus-Modul und das Modbus-Attr Modul. Ausserdem der Auszug aus dem Logfile wo ich auf die Adresse h261 den Wert 100 geschrieben habe. Der Wert wird jedoch nicht gesetzt. Zumindest nicht hierüber. Über hterm funktioniert es.

Modbus-Attr:

Code Auswählen Erweitern


defmod RTUWrite ModbusAttr 99 3600
attr RTUWrite userattr dev-h-combine dev-h-read dev-h-write dev-timing-timeout obj-h256-len obj-h256-reading obj-h256-set obj-h257-len obj-h257-reading obj-h257-set obj-h258-len obj-h258-reading obj-h258-set obj-h259-len obj-h259-reading obj-h259-set obj-h260-len obj-h260-reading obj-h260-set obj-h261-hint obj-h261-len obj-h261-max obj-h261-min obj-h261-reading obj-h261-set obj-h262-len obj-h262-max obj-h262-min obj-h262-reading obj-h262-set obj-h263-hint obj-h263-len obj-h263-max obj-h263-min obj-h263-reading obj-h263-set obj-h264-hint obj-h264-len obj-h264-max obj-h264-min obj-h264-reading obj-h264-set
attr RTUWrite dev-h-combine 9
attr RTUWrite dev-h-read 16
attr RTUWrite dev-h-write 16
attr RTUWrite dev-timing-timeout 4
attr RTUWrite obj-h256-reading 256
attr RTUWrite obj-h256-set 1
attr RTUWrite obj-h257-reading 257
attr RTUWrite obj-h257-set 1
attr RTUWrite obj-h258-reading 258
attr RTUWrite obj-h258-set 1
attr RTUWrite obj-h259-reading 259
attr RTUWrite obj-h259-set 1
attr RTUWrite obj-h260-reading 260
attr RTUWrite obj-h260-set 1
attr RTUWrite obj-h261-reading 261
attr RTUWrite obj-h261-set 1
attr RTUWrite obj-h262-reading 262
attr RTUWrite obj-h262-set 1
attr RTUWrite obj-h263-reading 263
attr RTUWrite obj-h263-set 1
attr RTUWrite obj-h264-reading 264
attr RTUWrite obj-h264-set 1
attr RTUWrite verbose 5


Modbus Modul:

Code Auswählen Erweitern


defmod ModbusLine Modbus /dev/ttyUSB0@9600,8,E,1
attr ModbusLine verbose 5


Auszug aus Log nach dem Schreiben auf h261:

Code Auswählen Erweitern


2019.10.11 22:05:54 5: RTUWrite: set called with 261 (h261) setVal = 100
2019.10.11 22:05:54 5: RTUWrite: GetSetChecks with force
2019.10.11 22:05:54 5: RTUWrite: GetSetChecks returns success
2019.10.11 22:05:54 5: RTUWrite: set packed hex 313030 with n to hex 0064
2019.10.11 22:05:54 4: RTUWrite: DoRequest called from Set created request: id 99, fCode 16, type h, adr 261, len 1, value 0064 for device RTUWrite reading 261 (set 261), read buffer empty
2019.10.11 22:05:54 5: ModbusLine: QueueRequest called from DoRequest (RTUWrite) with h261, qlen 0
2019.10.11 22:05:54 4: ModbusLine: ProcessRequestQueue called from QueueRequest, force, qlen 1, next entry to id 99 (RTUWrite), last send to this device was 515.146 secs ago, last read 515.118 secs ago, last read on bus 500.813 secs ago from id 99 (Quantum)
2019.10.11 22:05:54 5: ModbusLine: CheckDelay called from ProcessRequestQueue commDelay (0.1s since 21:57:19.717) for RTUWrite, delay 515.019secs over
2019.10.11 22:05:54 5: ModbusLine: CheckDelay called from ProcessRequestQueue sendDelay (0.1s since 21:57:19.689) for RTUWrite, delay 515.047secs over
2019.10.11 22:05:54 4: ModbusLine: ProcessRequestQueue (V4.1.5 - 17.9.2019) qlen 1, sending 631001050001020064064c request: id 99, fCode 16, type h, adr 261, len 1, value 0064 for device RTUWrite reading 261 (set 261), queued 0.00 secs ago, read buffer empty
2019.10.11 22:05:54 5: SW: 631001050001020064064c
2019.10.11 22:05:54 5: ModbusLine: StartQueueTimer called from ProcessRequestQueue removes internal timer because it is not needed now
2019.10.11 22:05:54 5: ModbusLine: ReadAnswer called from Set
2019.10.11 22:05:54 5: ModbusLine: ReadAnswer called and remaining timeout is 3.99469089508057
2019.10.11 22:05:54 5: ModbusLine: ReadAnswer got: 63
2019.10.11 22:05:54 5: ModbusLine: ReadAnswer got no valid frame after HandleFrameStart, wait for more data
2019.10.11 22:05:54 5: ModbusLine: ReadAnswer got: 6310
2019.10.11 22:05:54 5: ModbusLine: ReadAnswer got no valid frame after HandleFrameStart, wait for more data
2019.10.11 22:05:54 5: ModbusLine: ReadAnswer got: 631000
2019.10.11 22:05:54 5: ModbusLine: ReadAnswer got no valid frame after HandleFrameStart, wait for more data
2019.10.11 22:05:54 5: ModbusLine: ReadAnswer got: 63100000
2019.10.11 22:05:54 5: ModbusLine: ReadAnswer got no valid frame after HandleFrameStart, wait for more data
2019.10.11 22:05:54 5: ModbusLine: ReadAnswer got: 6310000000
2019.10.11 22:05:54 4: ModbusLine: ParseFrameStart (RTU) extracted id 99, fCode 16 and data 00
2019.10.11 22:05:54 5: ModbusLine: HandleResponse called from ReadAnswer
2019.10.11 22:05:54 5: ModbusLine: ParseResponse called from HandleResponse
2019.10.11 22:05:54 5: ModbusLine: ReadAnswer got: 631000000000
2019.10.11 22:05:54 4: ModbusLine: ParseFrameStart (RTU) extracted id 99, fCode 16 and data 0000
2019.10.11 22:05:54 5: ModbusLine: HandleResponse called from ReadAnswer
2019.10.11 22:05:54 5: ModbusLine: ParseResponse called from HandleResponse
2019.10.11 22:05:54 5: ModbusLine: HandleResponse did not get a valid frame yet, wait for more data
2019.10.11 22:05:54 5: ModbusLine: ReadAnswer got: 631000000000c8
2019.10.11 22:05:54 4: ModbusLine: ParseFrameStart (RTU) extracted id 99, fCode 16 and data 000000
2019.10.11 22:05:54 5: ModbusLine: HandleResponse called from ReadAnswer
2019.10.11 22:05:54 5: ModbusLine: ParseResponse called from HandleResponse
2019.10.11 22:05:54 5: ModbusLine: HandleResponse did not get a valid frame yet, wait for more data
2019.10.11 22:05:54 5: ModbusLine: ReadAnswer got: 631000000000c84b
2019.10.11 22:05:54 4: ModbusLine: ParseFrameStart (RTU) extracted id 99, fCode 16 and data 00000000
2019.10.11 22:05:54 5: ModbusLine: HandleResponse called from ReadAnswer
2019.10.11 22:05:54 5: ModbusLine: ParseResponse called from HandleResponse
2019.10.11 22:05:54 5: ModbusLine: CheckChecksum (called from HandleResponse): c84b is valid
2019.10.11 22:05:54 4: ModbusLine: ResponseDone request: id 99, fCode 16, type h, adr 261, len 1, value 0064 for device RTUWrite reading 261 (set 261), queued 0.04 secs ago, sent 0.04 secs ago, Current read buffer: 631000000000c84b, Id 99, fCode 16, response: id 99, fCode 16, type c, adr 261, len 1
2019.10.11 22:05:54 5: ModbusLine: DropFrame - drop 631000000000c84b
2019.10.11 22:05:54 5: RTUWrite: set is sending read after write
2019.10.11 22:05:54 4: RTUWrite: DoRequest called from Set created request: id 99, fCode 16, type h, adr 261, len 1 for device RTUWrite reading 261 (set 261 Rd), read buffer empty
2019.10.11 22:05:54 5: ModbusLine: QueueRequest called from DoRequest (RTUWrite) with h261, qlen 0
2019.10.11 22:05:54 4: ModbusLine: ProcessRequestQueue called from QueueRequest, force, qlen 1, next entry to id 99 (RTUWrite), last send to this device was 0.035 secs ago, last read 0.004 secs ago, last read on bus 0.005 secs ago from id 99 (RTUWrite)
2019.10.11 22:05:54 4: ModbusLine: CheckDelay called from ProcessRequestQueue commDelay (0.1s since 22:05:54.870) for RTUWrite, rest 0.095, sleep forced
2019.10.11 22:05:54 4: ModbusLine: CheckDelay called from ProcessRequestQueue sendDelay (0.1s since 22:05:54.839) for RTUWrite, rest 0.064, sleep forced
2019.10.11 22:05:54 4: ModbusLine: ProcessRequestQueue (V4.1.5 - 17.9.2019) qlen 1, sending 63100105000102308a92 request: id 99, fCode 16, type h, adr 261, len 1 for device RTUWrite reading 261 (set 261 Rd), queued 0.00 secs ago, read buffer empty
2019.10.11 22:05:54 5: SW: 63100105000102308a92
2019.10.11 22:05:54 5: ModbusLine: StartQueueTimer called from ProcessRequestQueue removes internal timer because it is not needed now
2019.10.11 22:05:54 5: ModbusLine: ReadAnswer called from Set
2019.10.11 22:05:54 5: ModbusLine: ReadAnswer called and remaining timeout is 3.99487614631653
2019.10.11 22:05:54 5: ModbusLine: ReadAnswer got: 63
2019.10.11 22:05:54 5: ModbusLine: ReadAnswer got no valid frame after HandleFrameStart, wait for more data
2019.10.11 22:05:54 5: ModbusLine: ReadAnswer got: 6310
2019.10.11 22:05:54 5: ModbusLine: ReadAnswer got no valid frame after HandleFrameStart, wait for more data
2019.10.11 22:05:54 5: ModbusLine: ReadAnswer got: 631000
2019.10.11 22:05:54 5: ModbusLine: ReadAnswer got no valid frame after HandleFrameStart, wait for more data
2019.10.11 22:05:54 5: ModbusLine: ReadAnswer got: 63100000
2019.10.11 22:05:54 5: ModbusLine: ReadAnswer got no valid frame after HandleFrameStart, wait for more data
2019.10.11 22:05:54 5: ModbusLine: ReadAnswer got: 6310000000
2019.10.11 22:05:54 4: ModbusLine: ParseFrameStart (RTU) extracted id 99, fCode 16 and data 00
2019.10.11 22:05:54 5: ModbusLine: HandleResponse called from ReadAnswer
2019.10.11 22:05:54 5: ModbusLine: ParseResponse called from HandleResponse
2019.10.11 22:05:54 5: ModbusLine: ReadAnswer got: 631000000000
2019.10.11 22:05:54 4: ModbusLine: ParseFrameStart (RTU) extracted id 99, fCode 16 and data 0000
2019.10.11 22:05:54 5: ModbusLine: HandleResponse called from ReadAnswer
2019.10.11 22:05:54 5: ModbusLine: ParseResponse called from HandleResponse
2019.10.11 22:05:54 5: ModbusLine: HandleResponse did not get a valid frame yet, wait for more data
2019.10.11 22:05:54 5: ModbusLine: ReadAnswer got: 631000000000c84b
2019.10.11 22:05:54 4: ModbusLine: ParseFrameStart (RTU) extracted id 99, fCode 16 and data 00000000
2019.10.11 22:05:54 5: ModbusLine: HandleResponse called from ReadAnswer
2019.10.11 22:05:54 5: ModbusLine: ParseResponse called from HandleResponse
2019.10.11 22:05:54 5: ModbusLine: CheckChecksum (called from HandleResponse): c84b is valid
2019.10.11 22:05:54 4: ModbusLine: ResponseDone request: id 99, fCode 16, type h, adr 261, len 1 for device RTUWrite reading 261 (set 261 Rd), queued 0.03 secs ago, sent 0.03 secs ago, Current read buffer: 631000000000c84b, Id 99, fCode 16, response: id 99, fCode 16, type c, adr 261, len 1
2019.10.11 22:05:54 5: ModbusLine: DropFrame - drop 631000000000c84b
2019.10.11 22:05:54 5: RTUWrite: StartQueueTimer called from Set removes internal timer because it is not needed now


Kannst Du hier irgendwas erkennen was da nicht passt?

Danke
Tino

[StefanStrobel]

Hallo Tino,

Du hast den Function-Code zum Schreiben und zum Lesen auf 16 gesetzt.
Damit überschreibst Du einen zuvor geschriebenen Wert beim vermeintlichen Lesen sofort wieder mit 0.
Siehe http://www.modbus.org/docs/Modbus_Application_Protocol_V1_1b.pdf

Bitte Probier doch mal den Code fürs Lesen auf seiner Default-Einstellung 3 zu belassen.

Gruß
    Stefan

[StefanStrobel]

Ergänzung:

Die Antwort des Geräts auf den Schreib-Request sieht leider auch nicht gut aus.
Kannst Du denn mit anderen Tools das Register 261 per Code 16 einzeln beschreiben?

Gruß
    Stefan