Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

On Broadcast write mbusd wait's for feedback and provides feedback #61

Closed
dgoo2308 opened this issue Jul 29, 2020 · 5 comments
Closed

Comments

@dgoo2308
Copy link
Contributor

A write to unitId 0 is considered a broadcast and no devices should acknowledge although mbusd wait's for a response from servers, which it should not do as the servers are not allowed to acknowledge this.

This leads also to resends due to the time-outs and blocks the bus during that time () of waiting 3 times for 8 bytes.

Log unpatched:

Jul 28 18:47:19 bpi-iot-ros-ai mbusd[30096]: 28 Jul 2020 18:47:19 conn[192.168.1.55]: state now is CONN_RQST_FUNC
Jul 28 18:47:19 bpi-iot-ros-ai mbusd[30096]: 28 Jul 2020 18:47:19 conn[192.168.1.55]: state now is CONN_RQST_TAIL
Jul 28 18:47:19 bpi-iot-ros-ai mbusd[30096]: 28 Jul 2020 18:47:19 conn[192.168.1.55]: request: [00][05][00][e5][ff][00]
Jul 28 18:47:19 bpi-iot-ros-ai mbusd[30096]: 28 Jul 2020 18:47:19 conn[192.168.1.55]: state now is CONN_TTY
Jul 28 18:47:19 bpi-iot-ros-ai mbusd[30096]: 28 Jul 2020 18:47:19 tty: state now is TTY_RQST
Jul 28 18:47:19 bpi-iot-ros-ai mbusd[30096]: 28 Jul 2020 18:47:19 tty: state now is TTY_RESP
Jul 28 18:47:19 bpi-iot-ros-ai mbusd[30096]: 28 Jul 2020 18:47:19 tty: estimated 8 bytes, waiting 508332 usec
Jul 28 18:47:20 bpi-iot-ros-ai mbusd[30096]: 28 Jul 2020 18:47:20 tty: response timeout
Jul 28 18:47:20 bpi-iot-ros-ai mbusd[30096]: 28 Jul 2020 18:47:20 tty: attempt to retry request (1 of 3)
Jul 28 18:47:20 bpi-iot-ros-ai mbusd[30096]: 28 Jul 2020 18:47:20 tty: state now is TTY_RQST
Jul 28 18:47:20 bpi-iot-ros-ai mbusd[30096]: 28 Jul 2020 18:47:20 tty: state now is TTY_RESP
Jul 28 18:47:20 bpi-iot-ros-ai mbusd[30096]: 28 Jul 2020 18:47:20 tty: estimated 8 bytes, waiting 508332 usec
Jul 28 18:47:20 bpi-iot-ros-ai mbusd[30096]: 28 Jul 2020 18:47:20 tty: response timeout
Jul 28 18:47:20 bpi-iot-ros-ai mbusd[30096]: 28 Jul 2020 18:47:20 tty: attempt to retry request (2 of 3)
Jul 28 18:47:20 bpi-iot-ros-ai mbusd[30096]: 28 Jul 2020 18:47:20 tty: state now is TTY_RQST
Jul 28 18:47:20 bpi-iot-ros-ai mbusd[30096]: 28 Jul 2020 18:47:20 tty: state now is TTY_RESP
Jul 28 18:47:20 bpi-iot-ros-ai mbusd[30096]: 28 Jul 2020 18:47:20 tty: estimated 8 bytes, waiting 508332 usec
Jul 28 18:47:21 bpi-iot-ros-ai mbusd[30096]: 28 Jul 2020 18:47:21 tty: response timeout
Jul 28 18:47:21 bpi-iot-ros-ai mbusd[30096]: 28 Jul 2020 18:47:21 tty: attempt to retry request (3 of 3)
Jul 28 18:47:21 bpi-iot-ros-ai mbusd[30096]: 28 Jul 2020 18:47:21 tty: state now is TTY_RQST
Jul 28 18:47:21 bpi-iot-ros-ai mbusd[30096]: 28 Jul 2020 18:47:21 tty: state now is TTY_RESP
Jul 28 18:47:21 bpi-iot-ros-ai mbusd[30096]: 28 Jul 2020 18:47:21 tty: estimated 8 bytes, waiting 508332 usec
Jul 28 18:47:21 bpi-iot-ros-ai mbusd[30096]: 28 Jul 2020 18:47:21 conn[192.168.1.55]: state now is CONN_RQST_FUNC
Jul 28 18:47:21 bpi-iot-ros-ai mbusd[30096]: 28 Jul 2020 18:47:21 conn[192.168.1.55]: state now is CONN_RQST_TAIL

# read starts within the broadcast cycle after 2 seconds wait!
Jul 28 18:47:21 bpi-iot-ros-ai mbusd[30096]: 28 Jul 2020 18:47:21 conn[192.168.1.55]: request: [14][04][00][08][00][03]
Jul 28 18:47:21 bpi-iot-ros-ai mbusd[30096]: 28 Jul 2020 18:47:21 conn[192.168.1.55]: state now is CONN_TTY
Jul 28 18:47:21 bpi-iot-ros-ai mbusd[30096]: 28 Jul 2020 18:47:21 tty: response timeout

solution tested for FC05 broadcast

diff --git a/src/conn.c b/src/conn.c
index 6540da7..d52a83a 100644
--- a/src/conn.c
+++ b/src/conn.c
@@ -556,35 +556,50 @@ conn_loop(void)
 #ifdef DEBUG
           logw(7, "tty: request written (total %d bytes)", tty.txlen);
 #endif
-          state_tty_set(&tty, TTY_RESP);
-          switch (tty.txbuf[1]) {
-            case 1:
-            case 2:
-              tty.rxlen = 5 + (tty.txbuf[4] * 256 + tty.txbuf[5] + 7)/8;
-              break;
-            case 3:
-            case 4:
-              tty.rxlen = 5 + tty.txbuf[5] * 2;
-              break;
-            case 7:
-              tty.rxlen = 5;
-              break;
-            case 11:
-            case 15:
-            case 16:
-              tty.rxlen = 8;
-              break;
-            default:
-              tty.rxlen = tty.txlen;
-              break;
-          }
-          if (tty.rxlen > TTY_BUFSIZE)
-            tty.rxlen = TTY_BUFSIZE;
-          tty.timer += DV(tty.rxlen, tty.bpc, tty.speed);
+		  if (tty.txbuf[1]==5 && tty.txbuf[0]==0 )
+		  { // broadcast FC05
+			  // DANNY at work
+			  tty.rxlen=0;
+			  logw(5, "tty: Done, Broadcast");
+			  tty.timer=0;
+			  tcflush(tty.fd, TCIFLUSH);
+			  state_tty_set(&tty, TTY_PAUSE);
+			  state_conn_set(actconn, CONN_HEADER);
+			  continue;
+		  }
+		  else
+		  {
+				state_tty_set(&tty, TTY_RESP);
+			  switch (tty.txbuf[1]) {
+				case 1:
+				case 2:
+				  tty.rxlen = 5 + (tty.txbuf[4] * 256 + tty.txbuf[5] + 7)/8;
+				  break;
+				case 3:
+				case 4:
+				  tty.rxlen = 5 + tty.txbuf[5] * 2;
+				  break;
+				case 7:
+				  tty.rxlen = 5;
+				  break;
+				case 11:
+				case 15:
+				case 16:
+				  tty.rxlen = 8;
+				  break;
+				default:
+				  tty.rxlen = tty.txlen;
+				  break;
+			  }
+				
+			  if (tty.rxlen > TTY_BUFSIZE)
+				tty.rxlen = TTY_BUFSIZE;
+			  tty.timer += DV(tty.rxlen, tty.bpc, tty.speed);
 #ifdef DEBUG
-          logw(5, "tty: estimated %d bytes, waiting %lu usec", tty.rxlen, tty.timer);
+			  logw(5, "tty: estimated %d bytes, waiting %lu usec", tty.rxlen, tty.timer);
 #endif
-        }
+			}
+		}
       }
 
     if (FD_ISSET(tty.fd, &sdsetrd))

Log with patched version:

Jul 29 00:05:50 bpi-iot-ros-ai mbusd[18405]: 29 Jul 2020 00:05:50 conn_loop(): select() returns 1
Jul 29 00:05:50 bpi-iot-ros-ai mbusd[18405]: 29 Jul 2020 00:05:50 conn[192.168.1.55]: state now is CONN_RQST_FUNC
Jul 29 00:05:50 bpi-iot-ros-ai mbusd[18405]: 29 Jul 2020 00:05:50 conn_loop(): select(): max_sd = 5, t_out = 000060:000000
Jul 29 00:05:50 bpi-iot-ros-ai mbusd[18405]: 29 Jul 2020 00:05:50 conn_loop(): select() returns 1
Jul 29 00:05:50 bpi-iot-ros-ai mbusd[18405]: 29 Jul 2020 00:05:50 conn[192.168.1.55]: read request fc 5
Jul 29 00:05:50 bpi-iot-ros-ai mbusd[18405]: 29 Jul 2020 00:05:50 conn[192.168.1.55]: state now is CONN_RQST_TAIL
Jul 29 00:05:50 bpi-iot-ros-ai mbusd[18405]: 29 Jul 2020 00:05:50 conn[192.168.1.55]: request: [00][05][00][e5][ff][00]
Jul 29 00:05:50 bpi-iot-ros-ai mbusd[18405]: 29 Jul 2020 00:05:50 conn[192.168.1.55]: state now is CONN_TTY
Jul 29 00:05:50 bpi-iot-ros-ai mbusd[18405]: 29 Jul 2020 00:05:50 tty: state now is TTY_RQST
Jul 29 00:05:50 bpi-iot-ros-ai mbusd[18405]: 29 Jul 2020 00:05:50 conn_loop(): select(): max_sd = 4, t_out = 000060:000000
Jul 29 00:05:50 bpi-iot-ros-ai mbusd[18405]: 29 Jul 2020 00:05:50 conn_loop(): select() returns 1
Jul 29 00:05:50 bpi-iot-ros-ai mbusd[18405]: 29 Jul 2020 00:05:50 tty: written 8 bytes
Jul 29 00:05:50 bpi-iot-ros-ai mbusd[18405]: 29 Jul 2020 00:05:50 tty: request written (total 8 bytes)
Jul 29 00:05:50 bpi-iot-ros-ai mbusd[18405]: 29 Jul 2020 00:05:50 tty: Done, Broadcast
Jul 29 00:05:50 bpi-iot-ros-ai mbusd[18405]: 29 Jul 2020 00:05:50 tty: state now is TTY_PAUSE
Jul 29 00:05:50 bpi-iot-ros-ai mbusd[18405]: 29 Jul 2020 00:05:50 conn[192.168.1.55]: state now is CONN_HEADER
Jul 29 00:05:50 bpi-iot-ros-ai mbusd[18405]: 29 Jul 2020 00:05:50 conn_loop(): select(): max_sd = 5, t_out = 000000:100000
Jul 29 00:05:50 bpi-iot-ros-ai mbusd[18405]: 29 Jul 2020 00:05:50 conn_loop(): select() returns 0
Jul 29 00:05:50 bpi-iot-ros-ai mbusd[18405]: 29 Jul 2020 00:05:50 tty: state now is TTY_READY
Jul 29 00:05:50 bpi-iot-ros-ai mbusd[18405]: 29 Jul 2020 00:05:50 conn_loop(): select(): max_sd = 5, t_out = 000060:000000
Jul 29 00:05:51 bpi-iot-ros-ai mbusd[18405]: 29 Jul 2020 00:05:51 conn_loop(): select() returns 1
Jul 29 00:05:51 bpi-iot-ros-ai mbusd[18405]: 29 Jul 2020 00:05:51 conn[192.168.1.55]: state now is CONN_RQST_FUNC
Jul 29 00:05:51 bpi-iot-ros-ai mbusd[18405]: 29 Jul 2020 00:05:51 conn_loop(): select(): max_sd = 5, t_out = 000060:000000
Jul 29 00:05:51 bpi-iot-ros-ai mbusd[18405]: 29 Jul 2020 00:05:51 conn_loop(): select() returns 1
Jul 29 00:05:51 bpi-iot-ros-ai mbusd[18405]: 29 Jul 2020 00:05:51 conn[192.168.1.55]: read request fc 4
Jul 29 00:05:51 bpi-iot-ros-ai mbusd[18405]: 29 Jul 2020 00:05:51 conn[192.168.1.55]: state now is CONN_RQST_TAIL

# read after broadcast start
Jul 29 00:05:51 bpi-iot-ros-ai mbusd[18405]: 29 Jul 2020 00:05:51 conn[192.168.1.55]: request: [14][04][00][08][00][03]
Jul 29 00:05:51 bpi-iot-ros-ai mbusd[18405]: 29 Jul 2020 00:05:51 conn[192.168.1.55]: state now is CONN_TTY
Jul 29 00:05:51 bpi-iot-ros-ai mbusd[18405]: 29 Jul 2020 00:05:51 tty: state now is TTY_RQST
Jul 29 00:05:51 bpi-iot-ros-ai mbusd[18405]: 29 Jul 2020 00:05:51 conn_loop(): select(): max_sd = 4, t_out = 000060:000000
Jul 29 00:05:51 bpi-iot-ros-ai mbusd[18405]: 29 Jul 2020 00:05:51 conn_loop(): select() returns 1
Jul 29 00:05:51 bpi-iot-ros-ai mbusd[18405]: 29 Jul 2020 00:05:51 tty: written 8 bytes
Jul 29 00:05:51 bpi-iot-ros-ai mbusd[18405]: 29 Jul 2020 00:05:51 tty: request written (total 8 bytes)
Jul 29 00:05:51 bpi-iot-ros-ai mbusd[18405]: 29 Jul 2020 00:05:51 tty: state now is TTY_RESP
Jul 29 00:05:51 bpi-iot-ros-ai mbusd[18405]: 29 Jul 2020 00:05:51 tty: estimated 11 bytes, waiting 509895 usec
Jul 29 00:05:51 bpi-iot-ros-ai mbusd[18405]: 29 Jul 2020 00:05:51 conn_loop(): select(): max_sd = 4, t_out = 000000:509895
Jul 29 00:05:51 bpi-iot-ros-ai mbusd[18405]: 29 Jul 2020 00:05:51 conn_loop(): select() returns 1
Jul 29 00:05:51 bpi-iot-ros-ai mbusd[18405]: 29 Jul 2020 00:05:51 tty: read 11 bytes
Jul 29 00:05:51 bpi-iot-ros-ai mbusd[18405]: 29 Jul 2020 00:05:51 tty: rx offset is 0
Jul 29 00:05:51 bpi-iot-ros-ai mbusd[18405]: 29 Jul 2020 00:05:51 tty: read 11 bytes of 11, offset 0
Jul 29 00:05:51 bpi-iot-ros-ai mbusd[18405]: 29 Jul 2020 00:05:51 tty: state now is TTY_PROC
Jul 29 00:05:51 bpi-iot-ros-ai mbusd[18405]: 29 Jul 2020 00:05:51 tty: response read (total 11 bytes, offset 0 bytes)
Jul 29 00:05:51 bpi-iot-ros-ai mbusd[18405]: 29 Jul 2020 00:05:51 tty: response is correct
Jul 29 00:05:51 bpi-iot-ros-ai mbusd[18405]: 29 Jul 2020 00:05:51 tty: response: [14][04][06][05][53][05][53][fe][99][66][8d]
Jul 29 00:05:51 bpi-iot-ros-ai mbusd[18405]: 29 Jul 2020 00:05:51 conn[192.168.1.55]: state now is CONN_RESP
Jul 29 00:05:51 bpi-iot-ros-ai mbusd[18405]: 29 Jul 2020 00:05:51 tty: state now is TTY_PAUSE
Jul 29 00:05:51 bpi-iot-ros-ai mbusd[18405]: 29 Jul 2020 00:05:51 conn_loop(): select(): max_sd = 5, t_out = 000000:100000
Jul 29 00:05:51 bpi-iot-ros-ai mbusd[18405]: 29 Jul 2020 00:05:51 conn_loop(): select() returns 1
Jul 29 00:05:51 bpi-iot-ros-ai mbusd[18405]: 29 Jul 2020 00:05:51 conn[192.168.1.55]: state now is CONN_HEADER
Jul 29 00:05:51 bpi-iot-ros-ai mbusd[18405]: 29 Jul 2020 00:05:51 conn_loop(): select(): max_sd = 5, t_out = 000000:099446
Jul 29 00:05:51 bpi-iot-ros-ai mbusd[18405]: 29 Jul 2020 00:05:51 conn_loop(): select() returns 0
Jul 29 00:05:51 bpi-iot-ros-ai mbusd[18405]: 29 Jul 2020 00:05:51 tty: state now is TTY_READY
Jul 29 00:05:51 bpi-iot-ros-ai mbusd[18405]: 29 Jul 2020 00:05:51 conn_loop(): select(): max_sd = 5, t_out = 000060:000000

Result no more timeouts and a working solution.

  1. Please advice if that would be the apropriate place to do this.
  2. I only changed for FC05, according spec that should be for all writes.
@3cky
Copy link
Owner

3cky commented Jul 30, 2020

Thanks for pointing to this issue. The problem seems to be more complex though. Since Modbus/TCP neither specifies Unit ID 0 as a broadcast address nor defines the broadcast function at all, some of Modbus/TCP slaves (especially old ones) could use zero ID as a valid unicast slave address. But I agree mbusd should handle zero Unit ID more gracefully. I'll look into it.

@dgoo2308
Copy link
Contributor Author

dgoo2308 commented Jul 31, 2020

@3cky Thanks.

Sorry but I thought mbusd was to provide a gateway to Modbus RTU, which (Modbus RTU) per spec defines that:

  • devices should not acknowledged a write on unitId 0
  • Clients should not wait for an acknowledge, nor retry a write on unitId 0.

I can say it does get very messy when devices e.g. arduino slaves start an action on a broadcast and repeated broadcasts come in.

PS: thank for sharing this lib, works like a charm.

@3cky
Copy link
Owner

3cky commented Aug 13, 2020

@dgoo2308 I've pushed the fix for RTU broadcast address writing, please test.

@dgoo2308
Copy link
Contributor Author

@3cky so sorry for delay, I I'll try to squeeze the test in before my holiday next week otherwise it will be the second week of September.

I did notice for the tests that FC5 broadcast, write coil, is not tested.

@dgoo2308
Copy link
Contributor Author

@3cky

looks very good, I did a quick test with libmodbus in c:

int main(int argc, const char * argv[])
{
	printf("ModBus version: %s\n",LIBMODBUS_VERSION_STRING);	
	modbus_t * CTX_Broadcast = modbus_new_tcp_pi("mbus-1.local", "502");
	if (CTX_Broadcast == NULL) {
		fprintf(stderr, "Unable to allocate libmodbus context\n");
		return -1;
	}

	if (modbus_connect(CTX_Broadcast) == -1) {
		fprintf(stderr, "Connection failed: %s\n", modbus_strerror(errno));
		modbus_free(CTX_Broadcast);
		return -1;
	}
	modbus_set_slave(CTX_Broadcast, 0);
	
/* output enable broadcast*/
	int r=modbus_write_register(CTX_Broadcast,13,0x1);
	if (r==-1)
	{
		fprintf(stderr, "Fail broadcast %s\n", modbus_strerror(errno));
	}
	modbus_close(CTX_Broadcast);
	modbus_free(CTX_Broadcast);
	return 0;
}

libmodbus still complains with Fail broadcast Operation timed out but that is an other problem to tackle.

results in a nice log without timeouts and no reply.

Aug 30 16:10:06 mbus-1 mbusd[912]: 30 Aug 2020 16:10:06 conn_loop(): select() returns 1
Aug 30 16:10:06 mbus-1 mbusd[912]: 30 Aug 2020 16:10:06 conn_open(): accepting connection from 192.168.1.75
Aug 30 16:10:06 mbus-1 mbusd[912]: 30 Aug 2020 16:10:06 queue_new_elem(): length now is 1
Aug 30 16:10:06 mbus-1 mbusd[912]: 30 Aug 2020 16:10:06 conn[192.168.1.75]: state now is CONN_HEADER
Aug 30 16:10:06 mbus-1 mbusd[912]: 30 Aug 2020 16:10:06 conn_loop(): select(): max_sd = 5, t_out = 000060:000000
Aug 30 16:10:06 mbus-1 mbusd[912]: 30 Aug 2020 16:10:06 conn_loop(): select() returns 1
Aug 30 16:10:06 mbus-1 mbusd[912]: 30 Aug 2020 16:10:06 conn[192.168.1.75]: state now is CONN_RQST_FUNC
Aug 30 16:10:06 mbus-1 mbusd[912]: 30 Aug 2020 16:10:06 conn_loop(): select(): max_sd = 5, t_out = 000060:000000
Aug 30 16:10:06 mbus-1 mbusd[912]: 30 Aug 2020 16:10:06 conn_loop(): select() returns 1
Aug 30 16:10:06 mbus-1 mbusd[912]: 30 Aug 2020 16:10:06 conn[192.168.1.75]: read request fc 6
Aug 30 16:10:06 mbus-1 mbusd[912]: 30 Aug 2020 16:10:06 conn[192.168.1.75]: state now is CONN_RQST_TAIL
Aug 30 16:10:06 mbus-1 mbusd[912]: 30 Aug 2020 16:10:06 conn[192.168.1.75]: request: [00][06][00][0d][00][01]
Aug 30 16:10:06 mbus-1 mbusd[912]: 30 Aug 2020 16:10:06 conn[192.168.1.75]: state now is CONN_TTY
Aug 30 16:10:06 mbus-1 mbusd[912]: 30 Aug 2020 16:10:06 tty: state now is TTY_RQST
Aug 30 16:10:06 mbus-1 mbusd[912]: 30 Aug 2020 16:10:06 conn_loop(): select(): max_sd = 4, t_out = 000060:000000
Aug 30 16:10:06 mbus-1 mbusd[912]: 30 Aug 2020 16:10:06 conn_loop(): select() returns 1
Aug 30 16:10:06 mbus-1 mbusd[912]: 30 Aug 2020 16:10:06 tty: written 8 bytes
Aug 30 16:10:06 mbus-1 mbusd[912]: 30 Aug 2020 16:10:06 tty: request written (total 8 bytes)
Aug 30 16:10:06 mbus-1 mbusd[912]: 30 Aug 2020 16:10:06 conn[192.168.1.75]: state now is CONN_HEADER
Aug 30 16:10:06 mbus-1 mbusd[912]: 30 Aug 2020 16:10:06 tty: state now is TTY_PAUSE
Aug 30 16:10:06 mbus-1 mbusd[912]: 30 Aug 2020 16:10:06 conn[192.168.1.75]: broadcast request sent
Aug 30 16:10:06 mbus-1 mbusd[912]: 30 Aug 2020 16:10:06 conn_loop(): select(): max_sd = 5, t_out = 000000:100000
Aug 30 16:10:06 mbus-1 mbusd[912]: 30 Aug 2020 16:10:06 conn_loop(): select() returns 0
Aug 30 16:10:06 mbus-1 mbusd[912]: 30 Aug 2020 16:10:06 tty: state now is TTY_READY
Aug 30 16:10:07 mbus-1 mbusd[912]: 30 Aug 2020 16:10:06 conn_loop(): select(): max_sd = 5, t_out = 000059:000000
Aug 30 16:10:07 mbus-1 mbusd[912]: 30 Aug 2020 16:10:07 conn_loop(): select() returns 1
Aug 30 16:10:07 mbus-1 mbusd[912]: 30 Aug 2020 16:10:07 conn_close(): closing connection from 192.168.1.75
Aug 30 16:10:07 mbus-1 mbusd[912]: 30 Aug 2020 16:10:07 queue_delete_elem(): length now is 0
Aug 30 16:10:07 mbus-1 mbusd[912]: 30 Aug 2020 16:10:07 conn_loop(): select(): max_sd = 4, t_out = 000060:000000

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants