search

3cky / mbusd

Open-source Modbus TCP to Modbus RTU (RS-232/485) gateway.
BSD 3-Clause "New" or "Revised" License
565 stars 216 forks source link

(Question) How to (only) log values sent? #73

Closed eikowagenknecht closed 3 years ago

eikowagenknecht commented 3 years ago

I'm currently experiencing a strange phenomena where one of my modbus devices "automatically" turns itself on. To investigate this further, my idea was to set the logging level in mbusd so that I can see what is sent to the device and when.

I discovered that up lo loglevel 4 sending does not create any log entries, in level 5 it begins to log the request but also very much information that I don't need like all read requests (which happen every 5 seconds) and lots of entries regarding the connection state, so there is very much data written. Logging the response needs an even higher loglevel.

This is currently logged for every command I send (21 lines):

05 Mar 2021 18:12:35 conn_open(): accepting connection from 192.168.40.39
05 Mar 2021 18:12:35 queue_new_elem(): length now is 1
05 Mar 2021 18:12:35 conn[192.168.40.39]: state now is CONN_HEADER
05 Mar 2021 18:12:35 conn[192.168.40.39]: state now is CONN_RQST_FUNC
05 Mar 2021 18:12:35 conn[192.168.40.39]: state now is CONN_RQST_TAIL
05 Mar 2021 18:12:35 conn[192.168.40.39]: request: [f7][06][00][64][00][00]
05 Mar 2021 18:12:35 conn[192.168.40.39]: state now is CONN_TTY
05 Mar 2021 18:12:35 tty: state now is TTY_RQST
05 Mar 2021 18:12:35 tty: state now is TTY_RESP
05 Mar 2021 18:12:35 tty: estimated 8 bytes, waiting 308332 usec
05 Mar 2021 18:12:35 tty: rx offset is 0
05 Mar 2021 18:12:35 tty: read 8 bytes of 8, offset 0
05 Mar 2021 18:12:35 tty: state now is TTY_PROC
05 Mar 2021 18:12:35 tty: response read (total 8 bytes, offset 0 bytes)
05 Mar 2021 18:12:35 tty: response is correct
05 Mar 2021 18:12:35 conn[192.168.40.39]: state now is CONN_RESP
05 Mar 2021 18:12:35 tty: state now is TTY_PAUSE
05 Mar 2021 18:12:35 conn[192.168.40.39]: state now is CONN_HEADER
05 Mar 2021 18:12:35 conn_close(): closing connection from 192.168.40.39
05 Mar 2021 18:12:35 queue_delete_elem(): length now is 0
05 Mar 2021 18:12:36 tty: state now is TTY_READY

This would be the information I'd like to log:

05 Mar 2021 18:12:35 conn[192.168.40.39]: request: [f7][06][00][64][00][00]
05 Mar 2021 18:12:35 conn[192.168.40.39]: response: [f7][06][00][64][00][00][dc][83]

Is there a possibility to achieve a log like this without generating tens of thousands of lines of logs?

3cky commented 3 years ago

Right now mbusd doesn't have an option to log request/responses only, but you could use -L- option to enable logging to stdout and then use filtering. Something like this:

mbusd -p /dev/ttyUSB0 -s 9600 -P 502 -d -v5 -L- | grep "request:\|response:" > log.txt

eikowagenknecht commented 3 years ago

Thanks for the workaround, that will do the trick for now :-)