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

mbusd stops responding and goes into spin shortly after being started #41

Closed
fredriklj opened this issue Jan 1, 2019 · 12 comments
Closed

Comments

@fredriklj
Copy link

Just started playing with mbusd to have a tcp interface to my modbus devices the RS485 bus (there is currently three devices on the bus). Maybe I'm doing something fundamental wrong, but I can't make much out of the debugging output.

Shortly, at least within a few minutes after being started, mbusd stops responding. When I run in the the foreground with debugging enabled I get the output below. Have played around with the timeout parameters (-T and -W respectively but can't get any difference). What could be the issue?

$ sudo ./mbusd -d -v 9 -p /dev/ttyPort0 -s 9600 -t
01 Jan 2019 17:11:14 mbusd-0.3.1 started...
01 Jan 2019 17:11:14 tty: state now is TTY_PAUSE
01 Jan 2019 17:11:14 conn_loop(): select(): max_sd = 4, t_out = 000000:100000
01 Jan 2019 17:11:14 conn_loop(): select() returns 0
01 Jan 2019 17:11:14 tty: state now is TTY_READY
01 Jan 2019 17:11:14 conn_loop(): select(): max_sd = 4, t_out = 000060:000000
01 Jan 2019 17:11:16 conn_loop(): select() returns 1
01 Jan 2019 17:11:16 conn_open(): accepting connection from 127.0.0.1
01 Jan 2019 17:11:16 queue_new_elem(): length now is 1
01 Jan 2019 17:11:16 conn[127.0.0.1]: state now is CONN_HEADER
01 Jan 2019 17:11:16 conn_loop(): select(): max_sd = 5, t_out = 000060:000000
01 Jan 2019 17:11:16 conn_loop(): select() returns 1
01 Jan 2019 17:11:16 conn[127.0.0.1]: state now is CONN_RQST_FUNC
01 Jan 2019 17:11:16 conn[127.0.0.1]: read request fc 3
01 Jan 2019 17:11:16 conn[127.0.0.1]: state now is CONN_RQST_TAIL
01 Jan 2019 17:11:16 conn[127.0.0.1]: request: [03][03][00][2b][00][01]
01 Jan 2019 17:11:16 conn[127.0.0.1]: state now is CONN_TTY
01 Jan 2019 17:11:16 tty: state now is TTY_RQST
01 Jan 2019 17:11:16 conn_loop(): select(): max_sd = 4, t_out = 000060:000000
01 Jan 2019 17:11:16 conn_loop(): select() returns 1
01 Jan 2019 17:11:16 tty: written 8 bytes
01 Jan 2019 17:11:16 tty: request written (total 8 bytes)
01 Jan 2019 17:11:16 tty: state now is TTY_RESP
01 Jan 2019 17:11:16 tty: estimated 7 bytes, waiting 515624 usec
01 Jan 2019 17:11:16 conn_loop(): select(): max_sd = 4, t_out = 000000:515624
01 Jan 2019 17:11:16 conn_loop(): select() returns 1
01 Jan 2019 17:11:16 tty: read 7 bytes
01 Jan 2019 17:11:16 tty: rx offset is 0
01 Jan 2019 17:11:16 tty: read 7 bytes of 7, offset 0
01 Jan 2019 17:11:16 tty: state now is TTY_PROC
01 Jan 2019 17:11:16 tty: response read (total 7 bytes, offset 0 bytes)
01 Jan 2019 17:11:16 tty: response is correct
01 Jan 2019 17:11:16 tty: response: [03][03][02][00][01][00][44]
01 Jan 2019 17:11:16 conn[127.0.0.1]: state now is CONN_RESP
01 Jan 2019 17:11:16 tty: state now is TTY_PAUSE
01 Jan 2019 17:11:16 conn_loop(): select(): max_sd = 5, t_out = 000000:100000
01 Jan 2019 17:11:16 conn_loop(): select() returns 1
01 Jan 2019 17:11:16 conn[127.0.0.1]: state now is CONN_HEADER
01 Jan 2019 17:11:16 conn_loop(): select(): max_sd = 5, t_out = 000000:099508
01 Jan 2019 17:11:16 conn_loop(): select() returns 1
01 Jan 2019 17:11:16 conn_close(): closing connection from 127.0.0.1
01 Jan 2019 17:11:16 queue_delete_elem(): length now is 0
01 Jan 2019 17:11:16 conn_loop(): select(): max_sd = 4, t_out = 000000:098566
01 Jan 2019 17:11:16 conn_loop(): select() returns 0
01 Jan 2019 17:11:16 tty: state now is TTY_READY
01 Jan 2019 17:11:16 conn_loop(): select(): max_sd = 4, t_out = 000060:000000
01 Jan 2019 17:11:23 conn_loop(): select() returns 1
01 Jan 2019 17:11:23 tty: dropped 0 bytes
01 Jan 2019 17:11:23 conn_loop(): select(): max_sd = 4, t_out = 000060:000000
01 Jan 2019 17:11:23 conn_loop(): select() returns 1
01 Jan 2019 17:11:23 tty: dropped 0 bytes
01 Jan 2019 17:11:23 conn_loop(): select(): max_sd = 4, t_out = 000060:000000
01 Jan 2019 17:11:23 conn_loop(): select() returns 1
01 Jan 2019 17:11:23 tty: dropped 0 bytes
01 Jan 2019 17:11:23 conn_loop(): select(): max_sd = 4, t_out = 000060:000000
01 Jan 2019 17:11:23 conn_loop(): select() returns 1
01 Jan 2019 17:11:23 tty: dropped 0 bytes
01 Jan 2019 17:11:23 conn_loop(): select(): max_sd = 4, t_out = 000060:000000
01 Jan 2019 17:11:23 conn_loop(): select() returns 1
01 Jan 2019 17:11:23 tty: dropped 0 bytes
01 Jan 2019 17:11:23 conn_loop(): select(): max_sd = 4, t_out = 000060:000000
01 Jan 2019 17:11:23 conn_loop(): select() returns 1
01 Jan 2019 17:11:23 tty: dropped 0 bytes
01 Jan 2019 17:11:23 conn_loop(): select(): max_sd = 4, t_out = 000060:000000
01 Jan 2019 17:11:23 conn_loop(): select() returns 1
01 Jan 2019 17:11:23 tty: dropped 0 bytes
01 Jan 2019 17:11:23 conn_loop(): select(): max_sd = 4, t_out = 000060:000000
01 Jan 2019 17:11:23 conn_loop(): select() returns 1
01 Jan 2019 17:11:23 tty: dropped 0 bytes
01 Jan 2019 17:11:23 conn_loop(): select(): max_sd = 4, t_out = 000060:000000
01 Jan 2019 17:11:23 conn_loop(): select() returns 1
01 Jan 2019 17:11:23 tty: dropped 0 bytes
01 Jan 2019 17:11:23 conn_loop(): select(): max_sd = 4, t_out = 000060:000000
01 Jan 2019 17:11:23 conn_loop(): select() returns 1
01 Jan 2019 17:11:23 tty: dropped 0 bytes
01 Jan 2019 17:11:23 conn_loop(): select(): max_sd = 4, t_out = 000060:000000
01 Jan 2019 17:11:23 conn_loop(): select() returns 1
01 Jan 2019 17:11:23 tty: dropped 0 bytes
01 Jan 2019 17:11:23 conn_loop(): select(): max_sd = 4, t_out = 000060:000000
01 Jan 2019 17:11:23 conn_loop(): select() returns 1
01 Jan 2019 17:11:23 tty: dropped 0 bytes
01 Jan 2019 17:11:23 conn_loop(): select(): max_sd = 4, t_out = 000060:000000
01 Jan 2019 17:11:23 conn_loop(): select() returns 1
01 Jan 2019 17:11:23 tty: dropped 0 bytes
01 Jan 2019 17:11:23 conn_loop(): select(): max_sd = 4, t_out = 000060:000000
01 Jan 2019 17:11:23 conn_loop(): select() returns 1
01 Jan 2019 17:11:23 tty: dropped 0 bytes
01 Jan 2019 17:11:23 conn_loop(): select(): max_sd = 4, t_out = 000060:000000
01 Jan 2019 17:11:23 conn_loop(): select() returns 1
01 Jan 2019 17:11:23 tty: dropped 0 bytes
01 Jan 2019 17:11:23 conn_loop(): select(): max_sd = 4, t_out = 000060:000000
01 Jan 2019 17:11:23 conn_loop(): select() returns 1
01 Jan 2019 17:11:23 tty: dropped 0 bytes
01 Jan 2019 17:11:23 conn_loop(): select(): max_sd = 4, t_out = 000060:000000
01 Jan 2019 17:11:23 conn_loop(): select() returns 1
01 Jan 2019 17:11:23 tty: dropped 0 bytes
01 Jan 2019 17:11:23 conn_loop(): select(): max_sd = 4, t_out = 000060:000000
01 Jan 2019 17:11:23 conn_loop(): select() returns 1
01 Jan 2019 17:11:23 tty: dropped 0 bytes
01 Jan 2019 17:11:23 conn_loop(): select(): max_sd = 4, t_out = 000060:000000
01 Jan 2019 17:11:23 conn_loop(): select() returns 1
01 Jan 2019 17:11:23 tty: dropped 0 bytes
01 Jan 2019 17:11:23 conn_loop(): select(): max_sd = 4, t_out = 000060:000000
01 Jan 2019 17:11:23 conn_loop(): select() returns 1
01 Jan 2019 17:11:23 tty: dropped 0 bytes
01 Jan 2019 17:11:23 conn_loop(): select(): max_sd = 4, t_out = 000060:000000
01 Jan 2019 17:11:23 conn_loop(): select() returns 1
01 Jan 2019 17:11:23 tty: dropped 0 bytes
01 Jan 2019 17:11:23 conn_loop(): select(): max_sd = 4, t_out = 000060:000000
01 Jan 2019 17:11:23 conn_loop(): select() returns 1
01 Jan 2019 17:11:23 tty: dropped 0 bytes
01 Jan 2019 17:11:23 conn_loop(): select(): max_sd = 4, t_out = 000060:000000
01 Jan 2019 17:11:23 conn_loop(): select() returns 1
01 Jan 2019 17:11:23 tty: dropped 0 bytes
01 Jan 2019 17:11:23 conn_loop(): select(): max_sd = 4, t_out = 000060:000000
01 Jan 2019 17:11:23 conn_loop(): select() returns 1
01 Jan 2019 17:11:23 tty: dropped 0 bytes
01 Jan 2019 17:11:23 conn_loop(): select(): max_sd = 4, t_out = 000060:000000
01 Jan 2019 17:11:23 conn_loop(): select() returns 1
01 Jan 2019 17:11:23 tty: dropped 0 bytes
01 Jan 2019 17:11:23 conn_loop(): select(): max_sd = 4, t_out = 000060:000000
01 Jan 2019 17:11:23 conn_loop(): select() returns 1
01 Jan 2019 17:11:23 tty: dropped 0 bytes
01 Jan 2019 17:11:23 conn_loop(): select(): max_sd = 4, t_out = 000060:000000
01 Jan 2019 17:11:23 conn_loop(): select() returns 1
01 Jan 2019 17:11:23 tty: dropped 0 bytes
01 Jan 2019 17:11:23 conn_loop(): select(): max_sd = 4, t_out = 000060:000000
01 Jan 2019 17:11:23 conn_loop(): select() returns 1
01 Jan 2019 17:11:23 tty: dropped

@fredriklj fredriklj changed the title mbusb stops responding and goes into infinite loop shortly after being started mbusd stops responding and goes into infinite loop shortly after being started Jan 2, 2019
@fredriklj fredriklj changed the title mbusd stops responding and goes into infinite loop shortly after being started mbusd stops responding and goes into spin shortly after being started Jan 2, 2019
@3cky
Copy link
Owner

3cky commented Jan 2, 2019

Hmm, interesting. Is mbusd the only master on the RS485 bus? Looks like mbusd is receiving some unexpected data from the bus while it's in idle state. Nevertheless, it shouldn't go into infinite loop in this case. I'll take a look into the code.

@fredriklj
Copy link
Author

Yes, it is the only master. There are three slaves: two energy meters and one HVAC system. I'll try to watch the interface to see if there is something unexpected being received on it..

@3cky
Copy link
Owner

3cky commented Jan 3, 2019

I did some fixes in serial port initialization code, please rebuild mbusd with the updated code and check is something changed or not.

@fredriklj
Copy link
Author

I investigated a bit further, it seems my device (FT232R USB UART) is being reset now and then, for yet unknown reasons. Anyway, output from updated code below:

$ sudo ./mbusd -d -v 9 -p /dev/ttyPort0 -s 9600 -t
03 Jan 2019 21:15:42 mbusd-0.3.1 started...
03 Jan 2019 21:15:42 tty: state now is TTY_PAUSE
03 Jan 2019 21:15:42 conn_loop(): select(): max_sd = 4, t_out = 000000:100000
03 Jan 2019 21:15:42 conn_loop(): select() returns 0
03 Jan 2019 21:15:42 tty: state now is TTY_READY
03 Jan 2019 21:15:42 conn_loop(): select(): max_sd = 4, t_out = 000060:000000
03 Jan 2019 21:15:55 conn_loop(): select() returns 1
03 Jan 2019 21:15:55 conn_open(): accepting connection from 127.0.0.1
03 Jan 2019 21:15:55 queue_new_elem(): length now is 1
03 Jan 2019 21:15:55 conn[127.0.0.1]: state now is CONN_HEADER
03 Jan 2019 21:15:55 conn_loop(): select(): max_sd = 5, t_out = 000060:000000
03 Jan 2019 21:15:55 conn_loop(): select() returns 1
03 Jan 2019 21:15:55 conn[127.0.0.1]: state now is CONN_RQST_FUNC
03 Jan 2019 21:15:55 conn[127.0.0.1]: read request fc 4
03 Jan 2019 21:15:55 conn[127.0.0.1]: state now is CONN_RQST_TAIL
03 Jan 2019 21:15:55 conn[127.0.0.1]: request: [03][04][00][0a][00][01]
03 Jan 2019 21:15:55 conn[127.0.0.1]: state now is CONN_TTY
03 Jan 2019 21:15:55 tty: state now is TTY_RQST
03 Jan 2019 21:15:55 conn_loop(): select(): max_sd = 4, t_out = 000060:000000
03 Jan 2019 21:15:55 conn_loop(): select() returns 1
03 Jan 2019 21:15:55 tty: written 8 bytes
03 Jan 2019 21:15:55 tty: request written (total 8 bytes)
03 Jan 2019 21:15:55 tty: state now is TTY_RESP
03 Jan 2019 21:15:55 tty: estimated 7 bytes, waiting 515624 usec
03 Jan 2019 21:15:55 conn_loop(): select(): max_sd = 4, t_out = 000000:515624
03 Jan 2019 21:15:55 conn_loop(): select() returns 1
03 Jan 2019 21:15:55 tty: read 7 bytes
03 Jan 2019 21:15:55 tty: rx offset is 0
03 Jan 2019 21:15:55 tty: read 7 bytes of 7, offset 0
03 Jan 2019 21:15:55 tty: state now is TTY_PROC
03 Jan 2019 21:15:55 tty: response read (total 7 bytes, offset 0 bytes)
03 Jan 2019 21:15:55 tty: response is correct
03 Jan 2019 21:15:55 tty: response: [03][04][02][00][00][c0][f0]
03 Jan 2019 21:15:55 conn[127.0.0.1]: state now is CONN_RESP
03 Jan 2019 21:15:55 tty: state now is TTY_PAUSE
03 Jan 2019 21:15:55 conn_loop(): select(): max_sd = 5, t_out = 000000:100000
03 Jan 2019 21:15:55 conn_loop(): select() returns 1
03 Jan 2019 21:15:55 conn[127.0.0.1]: state now is CONN_HEADER
03 Jan 2019 21:15:55 conn_loop(): select(): max_sd = 5, t_out = 000000:099859
03 Jan 2019 21:15:55 conn_loop(): select() returns 1
03 Jan 2019 21:15:55 conn[127.0.0.1]: state now is CONN_RQST_FUNC
03 Jan 2019 21:15:55 conn[127.0.0.1]: read request fc 4
03 Jan 2019 21:15:55 conn[127.0.0.1]: state now is CONN_RQST_TAIL
03 Jan 2019 21:15:55 conn[127.0.0.1]: request: [03][04][00][0c][00][01]
03 Jan 2019 21:15:55 conn[127.0.0.1]: state now is CONN_TTY
03 Jan 2019 21:15:55 conn_loop(): select(): max_sd = 4, t_out = 000000:098814
03 Jan 2019 21:15:55 conn_loop(): select() returns 0
03 Jan 2019 21:15:55 tty: state now is TTY_RQST
03 Jan 2019 21:15:55 conn_loop(): select(): max_sd = 4, t_out = 000059:000000
03 Jan 2019 21:15:55 conn_loop(): select() returns 1
03 Jan 2019 21:15:55 tty: written 8 bytes
03 Jan 2019 21:15:55 tty: request written (total 8 bytes)
03 Jan 2019 21:15:55 tty: state now is TTY_RESP
03 Jan 2019 21:15:55 tty: estimated 7 bytes, waiting 515624 usec
03 Jan 2019 21:15:55 conn_loop(): select(): max_sd = 4, t_out = 000000:515624
03 Jan 2019 21:15:55 conn_loop(): select() returns 1
03 Jan 2019 21:15:55 tty: read 7 bytes
03 Jan 2019 21:15:55 tty: rx offset is 0
03 Jan 2019 21:15:55 tty: read 7 bytes of 7, offset 0
03 Jan 2019 21:15:55 tty: state now is TTY_PROC
03 Jan 2019 21:15:55 tty: response read (total 7 bytes, offset 0 bytes)
03 Jan 2019 21:15:55 tty: response is correct
03 Jan 2019 21:15:55 tty: response: [03][04][02][00][00][c0][f0]
03 Jan 2019 21:15:55 conn[127.0.0.1]: state now is CONN_RESP
03 Jan 2019 21:15:55 tty: state now is TTY_PAUSE
03 Jan 2019 21:15:55 conn_loop(): select(): max_sd = 5, t_out = 000000:100000
03 Jan 2019 21:15:55 conn_loop(): select() returns 1
03 Jan 2019 21:15:55 conn[127.0.0.1]: state now is CONN_HEADER
03 Jan 2019 21:15:55 conn_loop(): select(): max_sd = 5, t_out = 000000:099861
03 Jan 2019 21:15:55 conn_loop(): select() returns 1
03 Jan 2019 21:15:55 conn[127.0.0.1]: state now is CONN_RQST_FUNC
03 Jan 2019 21:15:55 conn[127.0.0.1]: read request fc 4
03 Jan 2019 21:15:55 conn[127.0.0.1]: state now is CONN_RQST_TAIL
03 Jan 2019 21:15:55 conn[127.0.0.1]: request: [03][04][00][14][00][01]
03 Jan 2019 21:15:55 conn[127.0.0.1]: state now is CONN_TTY
03 Jan 2019 21:15:55 conn_loop(): select(): max_sd = 4, t_out = 000000:099716
03 Jan 2019 21:15:56 conn_loop(): select() returns 0
03 Jan 2019 21:15:56 tty: state now is TTY_RQST
03 Jan 2019 21:15:56 conn_loop(): select(): max_sd = 4, t_out = 000060:000000
03 Jan 2019 21:15:56 conn_loop(): select() returns 1
03 Jan 2019 21:15:56 tty: written 8 bytes
03 Jan 2019 21:15:56 tty: request written (total 8 bytes)
03 Jan 2019 21:15:56 tty: state now is TTY_RESP
03 Jan 2019 21:15:56 tty: estimated 7 bytes, waiting 515624 usec
03 Jan 2019 21:15:56 conn_loop(): select(): max_sd = 4, t_out = 000000:515624
03 Jan 2019 21:15:56 conn_loop(): select() returns 1
03 Jan 2019 21:15:56 tty: read 7 bytes
03 Jan 2019 21:15:56 tty: rx offset is 0
03 Jan 2019 21:15:56 tty: read 7 bytes of 7, offset 0
03 Jan 2019 21:15:56 tty: state now is TTY_PROC
03 Jan 2019 21:15:56 tty: response read (total 7 bytes, offset 0 bytes)
03 Jan 2019 21:15:56 tty: response is correct
03 Jan 2019 21:15:56 tty: response: [03][04][02][02][a4][c0][2b]
03 Jan 2019 21:15:56 conn[127.0.0.1]: state now is CONN_RESP
03 Jan 2019 21:15:56 tty: state now is TTY_PAUSE
03 Jan 2019 21:15:56 conn_loop(): select(): max_sd = 5, t_out = 000000:100000
03 Jan 2019 21:15:56 conn_loop(): select() returns 1
03 Jan 2019 21:15:56 conn[127.0.0.1]: state now is CONN_HEADER
03 Jan 2019 21:15:56 conn_loop(): select(): max_sd = 5, t_out = 000000:099863
03 Jan 2019 21:15:56 conn_loop(): select() returns 1
03 Jan 2019 21:15:56 conn[127.0.0.1]: state now is CONN_RQST_FUNC
03 Jan 2019 21:15:56 conn[127.0.0.1]: read request fc 3
03 Jan 2019 21:15:56 conn[127.0.0.1]: state now is CONN_RQST_TAIL
03 Jan 2019 21:15:56 conn[127.0.0.1]: request: [03][03][00][2b][00][01]
03 Jan 2019 21:15:56 conn[127.0.0.1]: state now is CONN_TTY
03 Jan 2019 21:15:56 conn_loop(): select(): max_sd = 4, t_out = 000000:099720
03 Jan 2019 21:15:56 conn_loop(): select() returns 0
03 Jan 2019 21:15:56 tty: state now is TTY_RQST
03 Jan 2019 21:15:56 conn_loop(): select(): max_sd = 4, t_out = 000060:000000
03 Jan 2019 21:15:56 conn_loop(): select() returns 1
03 Jan 2019 21:15:56 tty: written 8 bytes
03 Jan 2019 21:15:56 tty: request written (total 8 bytes)
03 Jan 2019 21:15:56 tty: state now is TTY_RESP
03 Jan 2019 21:15:56 tty: estimated 7 bytes, waiting 515624 usec
03 Jan 2019 21:15:56 conn_loop(): select(): max_sd = 4, t_out = 000000:515624
03 Jan 2019 21:15:56 conn_loop(): select() returns 1
03 Jan 2019 21:15:56 tty: read 7 bytes
03 Jan 2019 21:15:56 tty: rx offset is 0
03 Jan 2019 21:15:56 tty: read 7 bytes of 7, offset 0
03 Jan 2019 21:15:56 tty: state now is TTY_PROC
03 Jan 2019 21:15:56 tty: response read (total 7 bytes, offset 0 bytes)
03 Jan 2019 21:15:56 tty: response is correct
03 Jan 2019 21:15:56 tty: response: [03][03][02][00][02][40][45]
03 Jan 2019 21:15:56 conn[127.0.0.1]: state now is CONN_RESP
03 Jan 2019 21:15:56 tty: state now is TTY_PAUSE
03 Jan 2019 21:15:56 conn_loop(): select(): max_sd = 5, t_out = 000000:100000
03 Jan 2019 21:15:56 conn_loop(): select() returns 1
03 Jan 2019 21:15:56 conn[127.0.0.1]: state now is CONN_HEADER
03 Jan 2019 21:15:56 conn_loop(): select(): max_sd = 5, t_out = 000000:099860
03 Jan 2019 21:15:56 conn_loop(): select() returns 1
03 Jan 2019 21:15:56 conn_close(): closing connection from 127.0.0.1
03 Jan 2019 21:15:56 queue_delete_elem(): length now is 0
03 Jan 2019 21:15:56 conn_loop(): select(): max_sd = 4, t_out = 000000:076401
03 Jan 2019 21:15:56 conn_loop(): select() returns 0
03 Jan 2019 21:15:56 tty: state now is TTY_READY
03 Jan 2019 21:15:56 conn_loop(): select(): max_sd = 4, t_out = 000060:000000
03 Jan 2019 21:16:56 conn_loop(): select() returns 0
03 Jan 2019 21:16:56 conn_loop(): select(): max_sd = 4, t_out = 000060:000000
03 Jan 2019 21:17:01 conn_loop(): select() returns 1
03 Jan 2019 21:17:01 conn_open(): accepting connection from 127.0.0.1
03 Jan 2019 21:17:01 queue_new_elem(): length now is 1
03 Jan 2019 21:17:01 conn[127.0.0.1]: state now is CONN_HEADER
03 Jan 2019 21:17:01 conn_loop(): select(): max_sd = 5, t_out = 000060:000000
03 Jan 2019 21:17:01 conn_loop(): select() returns 1
03 Jan 2019 21:17:01 conn[127.0.0.1]: state now is CONN_RQST_FUNC
03 Jan 2019 21:17:01 conn[127.0.0.1]: read request fc 4
03 Jan 2019 21:17:01 conn[127.0.0.1]: state now is CONN_RQST_TAIL
03 Jan 2019 21:17:01 conn[127.0.0.1]: request: [01][04][01][56][00][02]
03 Jan 2019 21:17:01 conn[127.0.0.1]: state now is CONN_TTY
03 Jan 2019 21:17:01 tty: state now is TTY_RQST
03 Jan 2019 21:17:01 conn_loop(): select(): max_sd = 4, t_out = 000060:000000
03 Jan 2019 21:17:01 conn_loop(): select() returns 1
03 Jan 2019 21:17:01 tty: written 8 bytes
03 Jan 2019 21:17:01 tty: request written (total 8 bytes)
03 Jan 2019 21:17:01 tty: state now is TTY_RESP
03 Jan 2019 21:17:01 tty: estimated 9 bytes, waiting 517708 usec
03 Jan 2019 21:17:01 conn_loop(): select(): max_sd = 4, t_out = 000000:517708
03 Jan 2019 21:17:01 conn_loop(): select() returns 1
03 Jan 2019 21:17:01 tty: read 3 bytes
03 Jan 2019 21:17:01 tty: rx offset is 0
03 Jan 2019 21:17:01 tty: read 3 bytes of 9, offset 0
03 Jan 2019 21:17:01 conn_loop(): select(): max_sd = 4, t_out = 000000:501926
03 Jan 2019 21:17:01 conn_loop(): select() returns 1
03 Jan 2019 21:17:01 tty: read 0 bytes
03 Jan 2019 21:17:01 tty: read 3 bytes of 9, offset 0
03 Jan 2019 21:17:01 conn_loop(): select(): max_sd = 4, t_out = 000000:282062
03 Jan 2019 21:17:01 conn_loop(): select() returns 1
03 Jan 2019 21:17:01 tty: read 0 bytes
03 Jan 2019 21:17:01 tty: read 3 bytes of 9, offset 0
03 Jan 2019 21:17:01 conn_loop(): select(): max_sd = 4, t_out = 000000:281938
03 Jan 2019 21:17:01 conn_loop(): select() returns 1
03 Jan 2019 21:17:01 tty: read 0 bytes
03 Jan 2019 21:17:01 tty: read 3 bytes of 9, offset 0
03 Jan 2019 21:17:01 conn_loop(): select(): max_sd = 4, t_out = 000000:281817
03 Jan 2019 21:17:01 conn_loop(): select() returns 1
03 Jan 2019 21:17:01 tty: read 0 bytes
03 Jan 2019 21:17:01 tty: read 3 bytes of 9, offset 0
03 Jan 2019 21:17:01 conn_loop(): select(): max_sd = 4, t_out = 000000:281696
03 Jan 2019 21:17:01 conn_loop(): select() returns 1
03 Jan 2019 21:17:01 tty: read 0 bytes
03 Jan 2019 21:17:01 tty: read 3 bytes of 9, offset 0
03 Jan 2019 21:17:01 conn_loop(): select(): max_sd = 4, t_out = 000000:281574
03 Jan 2019 21:17:01 conn_loop(): select() returns 1
03 Jan 2019 21:17:01 tty: read 0 bytes
03 Jan 2019 21:17:01 tty: read 3 bytes of 9, offset 0
03 Jan 2019 21:17:01 conn_loop(): select(): max_sd = 4, t_out = 000000:281453
03 Jan 2019 21:17:01 conn_loop(): select() returns 1
03 Jan 2019 21:17:01 tty: read 0 bytes
03 Jan 2019 21:17:01 tty: read 3 bytes of 9, offset 0
03 Jan 2019 21:17:01 conn_loop(): select(): max_sd = 4, t_out = 000000:281332
03 Jan 2019 21:17:01 conn_loop(): select() returns 1
03 Jan 2019 21:17:01 tty: read 0 bytes
03 Jan 2019 21:17:01 tty: read 3 bytes of 9, offset 0
03 Jan 2019 21:17:01 conn_loop(): select(): max_sd = 4, t_out = 000000:281213
03 Jan 2019 21:17:01 conn_loop(): select() returns 1
03 Jan 2019 21:17:01 tty: read 0 bytes
03 Jan 2019 21:17:01 tty: read 3 bytes of 9, offset 0
03 Jan 2019 21:17:01 conn_loop(): select(): max_sd = 4, t_out = 000000:281096
03 Jan 2019 21:17:01 conn_loop(): select() returns 1
03 Jan 2019 21:17:01 tty: read 0 bytes
03 Jan 2019 21:17:01 tty: read 3 bytes of 9, offset 0
03 Jan 2019 21:17:01 conn_loop(): select(): max_sd = 4, t_out = 000000:280979
03 Jan 2019 21:17:01 conn_loop(): select() returns 1
03 Jan 2019 21:17:01 tty: read 0 bytes
03 Jan 2019 21:17:01 tty: read 3 bytes of 9, offset 0
03 Jan 2019 21:17:01 conn_loop(): select(): max_sd = 4, t_out = 000000:280861
03 Jan 2019 21:17:01 conn_loop(): select() returns 1
03 Jan 2019 21:17:01 tty: read 0 bytes
03 Jan 2019 21:17:01 tty: read 3 bytes of 9, offset 0
03 Jan 2019 21:17:01 conn_loop(): select(): max_sd = 4, t_out = 000000:280743
03 Jan 2019 21:17:01 conn_loop(): select() returns 1
03 Jan 2019 21:17:01 tty: read 0 bytes
03 Jan 2019 21:17:01 tty: read 3 bytes of 9, offset 0
03 Jan 2019 21:17:01 conn_loop(): select(): max_sd = 4, t_out = 000000:280627
03 Jan 2019 21:17:01 conn_loop(): select() returns 1
03 Jan 2019 21:17:01 tty: read 0 bytes
03 Jan 2019 21:17:01 tty: read 3 bytes of 9, offset 0
03 Jan 2019 21:17:01 conn_loop(): select(): max_sd = 4, t_out = 000000:280511
03 Jan 2019 21:17:01 conn_loop(): select() returns 1
03 Jan 2019 21:17:01 tty: read 0 bytes
03 Jan 2019 21:17:01 tty: read 3 bytes of 9, offset 0
03 Jan 2019 21:17:01 conn_loop(): select(): max_sd = 4, t_out = 000000:280393
03 Jan 2019 21:17:01 conn_loop(): select() returns 1
03 Jan 2019 21:17:01 tty: read 0 bytes
03 Jan 2019 21:17:01 tty: read 3 bytes of 9, offset 0
03 Jan 2019 21:17:01 conn_loop(): select(): max_sd = 4, t_out = 000000:280276
03 Jan 2019 21:17:01 conn_loop(): select() returns 1
03 Jan 2019 21:17:01 tty: read 0 bytes
03 Jan 2019 21:17:01 tty: read 3 bytes of 9, offset 0
03 Jan 2019 21:17:01 conn_loop(): select(): max_sd = 4, t_out = 000000:280158
03 Jan 2019 21:17:01 conn_loop(): select() returns 1
03 Jan 2019 21:17:01 tty: read 0 bytes
03 Jan 2019 21:17:01 tty: read 3 bytes of 9, offset 0
03 Jan 2019 21:17:01 conn_loop(): select(): max_sd = 4, t_out = 000000:280041
03 Jan 2019 21:17:01 conn_loop(): select() returns 1
03 Jan 2019 21:17:01 tty: read 0 bytes
03 Jan 2019 21:17:01 tty: read 3 bytes of 9, offset 0
03 Jan 2019 21:17:01 conn_loop(): select(): max_sd = 4, t_out = 000000:279923
03 Jan 2019 21:17:01 conn_loop(): select() returns 1
03 Jan 2019 21:17:01 tty: read 0 bytes
03 Jan 2019 21:17:01 tty: read 3 bytes of 9, offset 0
03 Jan 2019 21:17:01 conn_loop(): select(): max_sd = 4, t_out = 000000:279807
03 Jan 2019 21:17:01 conn_loop(): select() returns 1
03 Jan 2019 21:17:01 tty: read 0 bytes
03 Jan 2019 21:17:01 tty: read 3 bytes of 9, offset 0
03 Jan 2019 21:17:01 conn_loop(): select(): max_sd = 4, t_out = 000000:279691
03 Jan 2019 21:17:01 conn_loop(): select() returns 1
03 Jan 2019 21:17:01 tty: read 0 bytes
03 Jan 2019 21:17:01 tty: read 3 bytes of 9, offset 0
03 Jan 2019 21:17:01 conn_loop(): select(): max_sd = 4, t_out = 000000:279573
03 Jan 2019 21:17:01 conn_loop(): select() returns 1
03 Jan 2019 21:17:01 tty: read 0 bytes
03 Jan 2019 21:17:01 tty: read 3 bytes of 9, offset 0
03 Jan 2019 21:17:01 conn_loop(): select(): max_sd = 4, t_out = 000000:279455
03 Jan 2019 21:17:01 conn_loop(): select() returns 1
03 Jan 2019 21:17:01 tty: read 0 bytes
03 Jan 2019 21:17:01 tty: read 3 bytes of 9, offset 0
03 Jan 2019 21:17:01 conn_loop(): select(): max_sd = 4, t_out = 000000:279337
03 Jan 2019 21:17:01 conn_loop(): select() returns 1
03 Jan 2019 21:17:01 tty: read 0 bytes
03 Jan 2019 21:17:01 tty: read 3 bytes of 9, offset 0
03 Jan 2019 21:17:01 conn_loop(): select(): max_sd = 4, t_out = 000000:279220
03 Jan 2019 21:17:01 conn_loop(): select() returns 1
03 Jan 2019 21:17:01 tty: read 0 bytes
03 Jan 2019 21:17:01 tty: read 3 bytes of 9, offset 0
03 Jan 2019 21:17:01 conn_loop(): select(): max_sd = 4, t_out = 000000:279067
03 Jan 2019 21:17:01 conn_loop(): select() returns 1
03 Jan 2019 21:17:01 tty: read 0 bytes
03 Jan 2019 21:17:01 tty: read 3 bytes of 9, offset 0
03 Jan 2019 21:17:01 conn_loop(): select(): max_sd = 4, t_out = 000000:278951
03 Jan 2019 21:17:01 conn_loop(): select() returns 1
03 Jan 2019 21:17:01 tty: read 0 bytes
03 Jan 2019 21:17:01 tty: read 3 bytes of 9, offset 0
03 Jan 2019 21:17:01 conn_loop(): select(): max_sd = 4, t_out = 000000:278835
03 Jan 2019 21:17:01 conn_loop(): select() returns 1
03 Jan 2019 21:17:01 tty: read 0 bytes
03 Jan 2019 21:17:01 tty: read 3 bytes of 9, offset 0
03 Jan 2019 21:17:01 conn_loop(): select(): max_sd = 4, t_out = 000000:278716
03 Jan 2019 21:17:01 conn_loop(): select() returns 1
03 Jan 2019 21:17:01 tty: read 0 bytes
03 Jan 2019 21:17:01 tty: read 3 bytes of 9, offset 0
03 Jan 2019 21:17:01 conn_loop(): select(): max_sd = 4, t_out = 000000:278599
03 Jan 2019 21:17:01 conn_loop(): select() returns 1
03 Jan 2019 21:17:01 tty: read 0 bytes
03 Jan 2019 21:17:01 tty: read 3 bytes of 9, offset 0
03 Jan 2019 21:17:01 conn_loop(): select(): max_sd = 4, t_out = 000000:278463
03 Jan 2019 21:17:01 conn_loop(): select() returns 1
03 Jan 2019 21:17:01 tty: read 0 bytes
03 Jan 2019 21:17:01 tty: read 3 bytes of 9, offset 0
03 Jan 2019 21:17:01 conn_loop(): select(): max_sd = 4, t_out = 000000:278340
03 Jan 2019 21:17:01 conn_loop(): select() returns 1
03 Jan 2019 21:17:01 tty: read 0 bytes
03 Jan 2019 21:17:01 tty: read 3 bytes of 9, offset 0
03 Jan 2019 21:17:01 conn_loop(): select(): max_sd = 4, t_out = 000000:278050
03 Jan 2019 21:17:01 conn_loop(): select() returns 1
03 Jan 2019 21:17:01 tty: read 0 bytes
03 Jan 2019 21:17:01 tty: read 3 bytes of 9, offset 0
03 Jan 2019 21:17:01 conn_loop(): select(): max_sd = 4, t_out = 000000:277917
03 Jan 2019 21:17:01 conn_loop(): select() returns 1
03 Jan 2019 21:17:01 tty: read 0 bytes
03 Jan 2019 21:17:01 tty: read 3 bytes of 9, offset 0
03 Jan 2019 21:17:01 conn_loop(): select(): max_sd = 4, t_out = 000000:277781
03 Jan 2019 21:17:01 conn_loop(): select() returns 1
03 Jan 2019 21:17:01 tty: read 0 bytes
03 Jan 2019 21:17:01 tty: read 3 bytes of 9, offset 0
03 Jan 2019 21:17:01 conn_loop(): select(): max_sd = 4, t_out = 000000:277644
03 Jan 2019 21:17:01 conn_loop(): select() returns 1
03 Jan 2019 21:17:01 tty: read 0 bytes
03 Jan 2019 21:17:01 tty: read 3 bytes of 9, offset 0
03 Jan 2019 21:17:01 conn_loop(): select(): max_sd = 4, t_out = 000000:277521
03 Jan 2019 21:17:01 conn_loop(): select() returns 1
03 Jan 2019 21:17:01 tty: read 0 bytes
03 Jan 2019 21:17:01 tty: read 3 bytes of 9, offset 0
03 Jan 2019 21:17:01 conn_loop(): select(): max_sd = 4, t_out = 000000:277397
03 Jan 2019 21:17:01 conn_loop(): select() returns 1
03 Jan 2019 21:17:01 tty: read 0 bytes
03 Jan 2019 21:17:01 tty: read 3 bytes of 9, offset 0
03 Jan 2019 21:17:01 conn_loop(): select(): max_sd = 4, t_out = 000000:277274
03 Jan 2019 21:17:01 conn_loop(): select() returns 1
03 Jan 2019 21:17:01 tty: read 0 bytes
03 Jan 2019 21:17:01 tty: read 3 bytes of 9, offset 0
03 Jan 2019 21:17:01 conn_loop(): select(): max_sd = 4, t_out = 000000:277152
03 Jan 2019 21:17:01 conn_loop(): select() returns 1
03 Jan 2019 21:17:01 tty: read 0 bytes
03 Jan 2019 21:17:01 tty: read 3 bytes of 9, offset 0
03 Jan 2019 21:17:01 conn_loop(): select(): max_sd = 4, t_out = 000000:277029
03 Jan 2019 21:17:01 conn_loop(): select() returns 1
03 Jan 2019 21:17:01 tty: read 0 bytes
03 Jan 2019 21:17:01 tty: read 3 bytes of 9, offset 0
03 Jan 2019 21:17:01 conn_loop(): select(): max_sd = 4, t_out = 000000:276721
03 Jan 2019 21:17:01 conn_loop(): select() returns 1
03 Jan 2019 21:17:01 tty: read 0 bytes
03 Jan 2019 21:17:01 tty: read 3 bytes of 9, offset 0
03 Jan 2019 21:17:01 conn_loop(): select(): max_sd = 4, t_out = 000000:276523
03 Jan 2019 21:17:01 conn_loop(): select() returns 1
03 Jan 2019 21:17:01 tty: read 0 bytes
03 Jan 2019 21:17:01 tty: read 3 bytes of 9, offset 0
03 Jan 2019 21:17:01 conn_loop(): select(): max_sd = 4, t_out = 000000:276403
03 Jan 2019 21:17:01 conn_loop(): select() returns 1
03 Jan 2019 21:17:01 tty: read 0 bytes
03 Jan 2019 21:17:01 tty: read 3 bytes of 9, offset 0
03 Jan 2019 21:17:01 conn_loop(): select(): max_sd = 4, t_out = 000000:276124
03 Jan 2019 21:17:01 conn_loop(): select() returns 1
03 Jan 2019 21:17:01 tty: read 0 bytes
03 Jan 2019 21:17:01 tty: read 3 bytes of 9, offset 0
03 Jan 2019 21:17:01 conn_loop(): select(): max_sd = 4, t_out = 000000:275968
03 Jan 2019 21:17:01 conn_loop(): select() returns 1
03 Jan 2019 21:17:01 tty: read 0 bytes
03 Jan 2019 21:17:01 tty: read 3 bytes of 9, offset 0
03 Jan 2019 21:17:01 conn_loop(): select(): max_sd = 4, t_out = 000000:275812
03 Jan 2019 21:17:01 conn_loop(): select() returns 1
03 Jan 2019 21:17:01 tty: read 0 bytes
03 Jan 2019 21:17:01 tty: read 3 bytes of 9, offset 0
03 Jan 2019 21:17:01 conn_loop(): select(): max_sd = 4, t_out = 000000:275677
03 Jan 2019 21:17:01 conn_loop(): select() returns 1
03 Jan 2019 21:17:01 tty: read 0 bytes
03 Jan 2019 21:17:01 tty: read 3 bytes of 9, offset 0
03 Jan 2019 21:17:01 conn_loop(): select(): max_sd = 4, t_out = 000000:275451
03 Jan 2019 21:17:01 conn_loop(): select() returns 1
03 Jan 2019 21:17:01 tty: read 0 bytes
03 Jan 2019 21:17:01 tty: read 3 bytes of 9, offset 0
03 Jan 2019 21:17:01 conn_loop(): select(): max_sd = 4, t_out = 000000:275262
03 Jan 2019 21:17:01 conn_loop(): select() returns 1
03 Jan 2019 21:17:01 tty: read 0 bytes
03 Jan 2019 21:17:01 tty: read 3 bytes of 9, offset 0

3cky added a commit that referenced this issue Jan 4, 2019
@3cky
Copy link
Owner

3cky commented Jan 4, 2019

Indeed looks like hardware problem. I've added serial port reinitialization to avoid a "tty: read 0 bytes" message endless loop, but anyway this situation isn't seem normal to me. Could you please to try run your setup with the updated code?

@fredriklj
Copy link
Author

Yes, there is definitely a problem with the RS485 USB interface. After detecting the EOF it takes a while for it to re-appear. Tried the updated code, but mbusd still goes into spin:

$ sudo ./mbusd -d -v 9 -p /dev/ttyPort0 -s 9600 -t
04 Jan 2019 10:04:53 mbusd-0.3.1 started...
04 Jan 2019 10:04:53 tty: state now is TTY_PAUSE
04 Jan 2019 10:04:53 conn_loop(): select(): max_sd = 4, t_out = 000000:100000
04 Jan 2019 10:04:53 conn_loop(): select() returns 0
04 Jan 2019 10:04:53 tty: state now is TTY_READY
04 Jan 2019 10:04:53 conn_loop(): select(): max_sd = 4, t_out = 000060:000000
04 Jan 2019 10:04:58 conn_loop(): select() returns 1
04 Jan 2019 10:04:58 tty: error in read() (port closed)
04 Jan 2019 10:04:58 closing tty on error...
04 Jan 2019 10:04:58 tty closed, re-opening...
04 Jan 2019 10:04:58 conn_init(): can't open tty device /dev/ttyPort0 (No such file or directory)
04 Jan 2019 10:04:58 tty: dropped 0 bytes
04 Jan 2019 10:04:58 conn_loop(): select(): max_sd = 4, t_out = 000060:000000
04 Jan 2019 10:04:59 conn_loop(): select() returns 1
04 Jan 2019 10:04:59 conn_open(): accepting connection from 127.0.0.1
04 Jan 2019 10:04:59 queue_new_elem(): length now is 1
04 Jan 2019 10:04:59 conn[127.0.0.1]: state now is CONN_HEADER
04 Jan 2019 10:04:59 conn_loop(): select(): max_sd = 5, t_out = 000060:000000
04 Jan 2019 10:04:59 conn_loop(): select() returns 1
04 Jan 2019 10:04:59 conn[127.0.0.1]: state now is CONN_RQST_FUNC
04 Jan 2019 10:04:59 conn[127.0.0.1]: read request fc 4
04 Jan 2019 10:04:59 conn[127.0.0.1]: state now is CONN_RQST_TAIL
04 Jan 2019 10:04:59 conn[127.0.0.1]: request: [03][04][00][0a][00][01]
04 Jan 2019 10:04:59 conn[127.0.0.1]: state now is CONN_TTY
04 Jan 2019 10:04:59 tty: state now is TTY_RQST
04 Jan 2019 10:04:59 conn_loop(): select(): max_sd = 4, t_out = 000060:000000
04 Jan 2019 10:05:02 conn_loop(): select() returns 1
04 Jan 2019 10:05:02 conn_open(): accepting connection from 127.0.0.1
04 Jan 2019 10:05:02 queue_new_elem(): length now is 2
04 Jan 2019 10:05:02 conn[127.0.0.1]: state now is CONN_HEADER
04 Jan 2019 10:05:02 conn_loop(): select(): max_sd = 6, t_out = 000058:000000
04 Jan 2019 10:05:02 conn_loop(): select() returns 1
04 Jan 2019 10:05:02 conn_loop(): select(): max_sd = 6, t_out = 000058:000000
04 Jan 2019 10:05:02 conn_loop(): select() returns 1
04 Jan 2019 10:05:02 conn_loop(): select(): max_sd = 6, t_out = 000058:000000
04 Jan 2019 10:05:02 conn_loop(): select() returns 1
04 Jan 2019 10:05:02 conn_loop(): select(): max_sd = 6, t_out = 000058:000000
04 Jan 2019 10:05:02 conn_loop(): select() returns 1
04 Jan 2019 10:05:02 conn_loop(): select(): max_sd = 6, t_out = 000058:000000
04 Jan 2019 10:05:02 conn_loop(): select() returns 1
04 Jan 2019 10:05:02 conn_loop(): select(): max_sd = 6, t_out = 000058:000000
04 Jan 2019 10:05:02 conn_loop(): select() returns 1
04 Jan 2019 10:05:02 conn_loop(): select(): max_sd = 6, t_out = 000058:000000
04 Jan 2019 10:05:02 conn_loop(): select() returns 1
04 Jan 2019 10:05:02 conn_loop(): select(): max_sd = 6, t_out = 000058:000000
04 Jan 2019 10:05:02 conn_loop(): select() returns 1
04 Jan 2019 10:05:02 conn_loop(): select(): max_sd = 6, t_out = 000058:000000
04 Jan 2019 10:05:02 conn_loop(): select() returns 1
04 Jan 2019 10:05:02 conn_loop(): select(): max_sd = 6, t_out = 000058:000000
04 Jan 2019 10:05:02 conn_loop(): select() returns 1
04 Jan 2019 10:05:02 conn_loop(): select(): max_sd = 6, t_out = 000058:000000
04 Jan 2019 10:05:02 conn_loop(): select() returns 1
04 Jan 2019 10:05:02 conn_loop(): select(): max_sd = 6, t_out = 000058:000000
04 Jan 2019 10:05:02 conn_loop(): select() returns 1
04 Jan 2019 10:05:02 conn_loop(): select(): max_sd = 6, t_out = 000058:000000
04 Jan 2019 10:05:02 conn_loop(): select() returns 1
04 Jan 2019 10:05:02 conn_loop(): select(): max_sd = 6, t_out = 000058:000000
04 Jan 2019 10:05:02 conn_loop(): select() returns 1
04 Jan 2019 10:05:02 conn_loop(): select(): max_sd = 6, t_out = 000058:000000
04 Jan 2019 10:05:02 conn_loop(): select() returns 1
04 Jan 2019 10:05:02 conn_loop(): select(): max_sd = 6, t_out = 000058:000000
04 Jan 2019 10:05:02 conn_loop(): select() returns 1
04 Jan 2019 10:05:02 conn_loop(): select(): max_sd = 6, t_out = 000058:000000
04 Jan 2019 10:05:02 conn_loop(): select() returns 1
04 Jan 2019 10:05:02 conn_loop(): select(): max_sd = 6, t_out = 000058:000000
04 Jan 2019 10:05:02 conn_loop(): select() returns 1
04 Jan 2019 10:05:02 conn_loop(): select(): max_sd = 6, t_out = 000058:000000
04 Jan 2019 10:05:02 conn_loop(): select() returns 1
04 Jan 2019 10:05:02 conn_loop(): select(): max_sd = 6, t_out = 000058:000000
04 Jan 2019 10:05:02 conn_loop(): select() returns 1
04 Jan 2019 10:05:02 conn_loop(): select(): max_sd = 6, t_out = 000058:000000
04 Jan 2019 10:05:02 conn_loop(): select() returns 1
04 Jan 2019 10:05:02 conn_loop(): select(): max_sd = 6, t_out = 000058:000000
04 Jan 2019 10:05:02 conn_loop(): select() returns 1
04 Jan 2019 10:05:02 conn_loop(): select(): max_sd = 6, t_out = 000058:000000
04 Jan 2019 10:05:02 conn_loop(): select() returns 1
04 Jan 2019 10:05:02 conn_loop(): select(): max_sd = 6, t_out = 000058:000000
04 Jan 2019 10:05:02 conn_loop(): select() returns 1
04 Jan 2019 10:05:02 conn_loop(): select(): max_sd = 6, t_out = 000058:000000
04 Jan 2019 10:05:02 conn_loop(): select() returns 1
04 Jan 2019 10:05:02 conn_loop(): select(): max_sd = 6, t_out = 000058:000000
04 Jan 2019 10:05:02 conn_loop(): select() returns 1
04 Jan 2019 10:05:02 conn_loop(): select(): max_sd = 6, t_out = 000058:000000
04 Jan 2019 10:05:02 conn_loop(): select() returns 1
04 Jan 2019 10:05:02 conn_loop(): select(): max_sd = 6, t_out = 000058:000000
04 Jan 2019 10:05:02 conn_loop(): select() returns 1
04 Jan 2019 10:05:02 conn_loop(): select(): max_sd = 6, t_out = 000058:000000
04 Jan 2019 10:05:02 conn_loop(): select() returns 1
04 Jan 2019 10:05:02 conn_loop(): select(): max_sd = 6, t_out = 000058:000000
04 Jan 2019 10:05:02 conn_loop(): select() returns 1
04 Jan 2019 10:05:02 conn_loop(): select(): max_sd = 6, t_out = 000058:000000
04 Jan 2019 10:05:02 conn_loop(): select() returns 1
04 Jan 2019 10:05:02 conn_loop(): select(): max_sd = 6, t_out = 000058:000000
04 Jan 2019 10:05:02 conn_loop(): select() returns 1

@3cky
Copy link
Owner

3cky commented Jan 4, 2019

@fredriklj I've implemented a more robust serial port reconnect algorithm in b5e3c53, please test.

@fredriklj
Copy link
Author

Nice. It has been running smoothly now for about half an hour:

04 Jan 2019 19:07:06 conn_loop(): select() returns 1
04 Jan 2019 19:07:06 tty: error in read() (port closed)
04 Jan 2019 19:07:06 trying to re-open tty...
04 Jan 2019 19:07:06 tty re-opening...
04 Jan 2019 19:07:06 tty_reopen(): can't open tty device /dev/ttyPort0 (No such device)
04 Jan 2019 19:07:06 tty re-opening...
04 Jan 2019 19:07:06 tty_reopen(): can't open tty device /dev/ttyPort0 (No such file or directory)
04 Jan 2019 19:07:06 tty re-opening...
04 Jan 2019 19:07:06 tty_reopen(): can't open tty device /dev/ttyPort0 (No such file or directory)
04 Jan 2019 19:07:06 tty re-opening...
04 Jan 2019 19:07:06 tty: state now is TTY_PAUSE
04 Jan 2019 19:07:06 tty re-opened.

@3cky
Copy link
Owner

3cky commented Jan 5, 2019

Great, did you find the cause of the adapter resets? Is it mbusd related, or it's also observed with other software?

@fredriklj
Copy link
Author

I can observe EOF by just "sudo od -x < /dev/ttyPort0", so that part does not seem mbusd related. I will investigate further to see if it is the USB-RS485 misbehaving, or something at the bus.

@fredriklj
Copy link
Author

Currently I suspect the error to have been a bad USB cable which picked up electro-magnetic interference from the environment. After having replaced it the re-connection errors seem to have gone away!

@3cky
Copy link
Owner

3cky commented Jan 7, 2019

That's great! Glad you sorted this out. Thank you for the participation, I'll close this issue, feel free to reopen it or create new one in case of further problems.

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