Cloud-Automation / node-modbus

Modbus TCP Client/Server implementation for Node.JS
472 stars 176 forks source link

modbus rtu Request timed out #195

Closed LogicNode closed 6 years ago

LogicNode commented 6 years ago

Hello, I am having an issue trying to connect to salve device through Modbus RTU with ReadHoldingRegisters.js using the code below, I am getting the error: { '0': { err: 'Timeout', message: 'Request timed out' } } { '0': null }

Could you help please? thanks in advance!

let SerialPort = require('serialport')
let socket = new SerialPort('COM6', {
  baudRate: 19200,
  Parity: 'none',
  stopBits: 1,
  dataBits: 8
})
//set Slave PLC ID
let client = new modbus.client.RTU(socket , 1)

socket.on('close', function () {
  console.log(arguments)
})

socket.on('open', function () {
  console.log('opened');
  client.readDiscreteInputs(1,1)
    .then(function (resp) {
      console.log(resp)
      socket.close()
    }).catch(function () {
      console.error(arguments)
      socket.close()
    })
})

socket.on('data', function () {
  console.log(arguments)
})

socket.on('error', console.error)
stefanpoeter commented 6 years ago

In the example you execute a readDiscreteInputs request and no ReadHoldingRegisters request.

LogicNode commented 6 years ago

Sorry for that! even with readHoldingRegisters(1,1) i have the same error

stefanpoeter commented 6 years ago

Have you tried connecting to the Device without using the modbus lib. Something like minicom etc. to see if a connection can be established?

LogicNode commented 6 years ago

Yes, I have tried that with Modpoll 3.4 Master Modbus app and data was successfully returned from the PLC controller/Salve Device. i noticed also that the USB-RS 485 converter TX/RX was not blinking during readHoldingRegisters.js execution

stefanpoeter commented 6 years ago

Do you use Linux? The serialport has some issues when used with Linux.

LogicNode commented 6 years ago

I am using Windows 10.

stefanpoeter commented 6 years ago

Can you enable the log output (by setting the DEBUG environment variable to *) and post the output?

LogicNode commented 6 years ago

excuse me for the question, where should i place DEBUG line and how the line is written like debug: *; thanks :)

stefanpoeter commented 6 years ago

Just start your application like this DEBUG=* node yourscript.js

I am not using windows 10 a lot, so thats all I can give you https://superuser.com/questions/949560/how-do-i-set-system-environment-variables-in-windows-10

LogicNode commented 6 years ago

i have executed this: node inspect readholdingregisters.js output generated: `< Debugger listening on ws://127.0.0.1:9229/a09d2281-5f1f-46b0-b9c5-5c37245fe7b4 < For help see https://nodejs.org/en/docs/inspector Break on start in readholdingregisters.js:1

1 (function (exports, require, module, filename, dirname) { let modbus = require('jsmodbus') 2 let SerialPort = require('serialport') 3 let socket = new SerialPort('COM6', {`

stefanpoeter commented 6 years ago

That's the debugger, not what I meant. I need to take a look at the debugging messages generated by jsmodbus. See the link above on how to set environment variables for Windows 10 and set the DEBUG Variable to * and post the console output.

LogicNode commented 6 years ago

log generated:

serialport:binding:auto-detect loading WindowsBinding +0ms serialport:main opening path: COM6 +0ms serialport:bindings open +0ms serialport:main _read queueing _read for after open +0ms serialport:main opened path: COM6 +203ms opened modbus-client issuing new read holding registers request +0ms rtu-client-request-handler registrating new request +0ms user-request creating new user request with timeout 5000 +0ms client-request-handler flushing +0ms client-request-handler flushing new request <Buffer 01 03 00 00 00 01 c0 a1> +0ms serialport:main _write 8 bytes of data +16ms serialport:bindings write 8 bytes +219ms serialport:main _read reading +15ms serialport:bindings read +15ms serialport:main binding.write write finished +0ms client-request-handler request fully flushed, ( error: undefined ) undefined +15ms client-request-handler flushing +5s client-request-handler no request to be executed +0ms { '0': { err: 'Timeout', message: 'Request timed out' } } serialport:main #close +5s serialport:bindings close +5s serialport:main binding.read error { Error: Reading from COM port (ReadIOCompletion): Operation aborted canceled: true } +0ms serialport:main _read queueing _read for after open +0ms serialport:main binding.close finished +62ms { '0': null }

stefanpoeter commented 6 years ago

serialport:main #close +5s serialport:bindings close +5s serialport:main binding.read error { Error: Reading from COM port (ReadIOCompletion): Operation aborted canceled: true } +0ms serialport:main _read queueing _read for after open +0ms serialport:main binding.close finished +62ms

Seems like everything is fine to me except the part i quoted. Open up a issue on the serialport module an see what they have to say. I'll examin the

client-request-handler flushing new request <Buffer 01 03 00 00 00 01 c0 a1> +0ms

part and see if everything is fine. Maybe the Modbus Master just didn't feel responsible because of a missmatched packet or wrong unit id.

LogicNode commented 6 years ago

Thanks stefanpoeter, i opened the issue in Serialport module page and still waiting for an answer.

stefanpoeter commented 6 years ago

client-request-handler flushing new request <Buffer 01 03 00 00 00 01 c0 a1> +0ms

From this I would say you are sending the packet to a unit with id 1. The request is a read holding request with offset zero and count 1. Is this correct?

LogicNode commented 6 years ago

Yes, i'm trying to read from only one Register ,address: 40001

stefanpoeter commented 6 years ago

If the offset or count is wrong then you would get an exception response. Have you checked the unit id on the device? It must be 1!

LogicNode commented 6 years ago

Yes the ID is 1, Modbus settings are as below:

modbus settgins

stefanpoeter commented 6 years ago

Mhhh, checked the crc, it is ok as well. Last thing I can think of is the endiannes, can you check that on the device?

LogicNode commented 6 years ago

The device does not have any options for data formatting, so the error is in binding data to serial port? right! i will keep trying and may change the USB-to-RS485 converter and see if it works out!

stefanpoeter commented 6 years ago

Is there some mentioning in the documentation of your device wheather it is a big or little endian device?

LogicNode commented 6 years ago

I have searched the documentation, it is not mentioning endian type.

LogicNode commented 6 years ago

I've used Logic Analyzer to sniff binary on TX,RX between RS-485 converter terminals and the RTU gateway, screenshots of capture:

  1. Sessions 1 (excuting node readHoldingRegisters.js) 2018-06-18 16_14_49-failedbase sr - pulseviewfaileddd
  2. Session 2 (using modpoll3.4 windows application) Request 2018-06-18 13_11_20-session 3 - pulseview
  3. Session 2 (using modpoll3.4 windows application) Response 2018-06-18 13_12_11-session 3 - pulseview

Notes:

  1. Endian type is Little endian as i did set it in Logic Analyzer as LSB first and when i set MSB data is corrupted.
  2. from session 1 the HR address is shifted 1 Register while it is one in the code.
  3. Buffer value is different between session 1 and session 2.

thanks.

stefanpoeter commented 6 years ago

The data transfered are not represented in session 1. That should be <01 03 00 00 00 01 c0 a1> but for some reason there are missing some bytes.

Can you instantiate a serialport and write some values to the serialport socket like this:

socket.write(Buffer.from([01,03,00,00,00,01,c0,a1]);

See if you get the same results. This way we can rule our jsmodbus as a the source of the error.

LogicNode commented 6 years ago

with this socket.on('open', function () { console.log('opened'); socket.write(Buffer.from([0x01,0x03,0x00,0x00,0x00,0x01,0xc0,0xa1])) }) i got F:\ocnplcx\nodeapps0>node readholdingregisters serialport:binding:auto-detect loading WindowsBinding +0ms serialport:main opening path: COM5 +0ms serialport:bindings open +0ms serialport:main _read queueing _read for after open +4ms serialport:main opened path: COM5 +90ms opened serialport:main _write 8 bytes of data +3ms serialport:bindings write 8 bytes +97ms serialport:main _read reading +1ms serialport:bindings read +1ms serialport:main binding.write write finished +2ms

stefanpoeter commented 6 years ago

Can you wait for some data on the socket an print it to the console? Also sniff the data with the tools u used above.

LogicNode commented 6 years ago

Buffer writing test 2: socket.write(Buffer.from([0x01,0x03,0x00,0x00,0x00,0x01,0xc0,0xa1])) Capture: 2018-06-19 12_16_48-session 1 - pulseview Request 2018-06-19 12_15_59-session 1 - pulseview Response Err after aprox 27 seconds on 2018-06-19 12_18_06-session 1 - pulseview

stefanpoeter commented 6 years ago

I think the sniffing tool is misinterpreting your request.

screenshot_20180619-114056-01

First there is the start address following the register count, but that does not explain why there isn't a response from the slave. Can you issue the same request with a working modbus client so that I can recheck the crc?

LogicNode commented 6 years ago

Yes you are right but, The polling was successful using the same Buffer polled by working Mod-bus client: socket.on('open', function () { console.log('opened'); socket.write(Buffer.from([0x01,0x03,0x00,0x00,0x00,0x01,0x84,0x0a])) })

Request: 2018-06-19 12_47_19-session 1 - pulseview

Response: 2018-06-19 12_47_42-session 1 - pulseview

stefanpoeter commented 6 years ago

Then I need to replace the crc module. I am on holiday till next Tuesday, then I will see what I can do. Feel free to make a pull request in the meantime.

LogicNode commented 6 years ago

i really appreciate your efforts Stefan,thank you.

stefanpoeter commented 6 years ago

I did a quick test and it seems that the slave id needs to be part of the crc buffer. So a fix should be very quick and easy.

screenshot_20180619-121012-01

stefanpoeter commented 6 years ago

I couldn't resist. Made a new branch from my smartphone. Checkout v3.0.1_dev and see if it works now.

LogicNode commented 6 years ago

Great job! but i couldn't find version jsmodbus@3.0.1_dev

stefanpoeter commented 6 years ago

You need to check it out from the repo. It is not published yet.

LogicNode commented 6 years ago

Now the buffer is good except the crc two hex digits should be swapped as the previous successful request: 2018-06-19 12_47_19-session 1 - pulseview Buffer sniffed using Sigrok Pulseview + Saleae Logic Analyzer

Current Buffer Debug for version 3.0.1_dev client-request-handler flushing new request <Buffer 01 03 00 00 00 01 0a 84> +4ms

stefanpoeter commented 6 years ago

try again, i made an update.

LogicNode commented 6 years ago

Output: serialport:binding:auto-detect loading WindowsBinding +0ms serialport:main opening path: COM5 +0ms serialport:bindings open +0ms serialport:main _read queueing _read for after open +5ms serialport:main opened path: COM5 +89ms opened modbus-client issuing new read holding registers request +0ms rtu-client-request-handler registrating new request +0ms user-request creating new user request with timeout 5000 +0ms client-request-handler flushing +0ms client-request-handler flushing new request <Buffer 00 00 00> +2ms serialport:main _write 3 bytes of data +9ms serialport:bindings write 3 bytes +102ms serialport:main _read reading +3ms serialport:bindings read +3ms serialport:main binding.write write finished +4ms client-request-handler request fully flushed, ( error: undefined ) undefined +10ms client-request-handler flushing +5s client-request-handler no request to be executed +1ms { '0': { err: 'Timeout', message: 'Request timed out' } } serialport:main #close +5s serialport:bindings close +5s serialport:main binding.read error { Error: Reading from COM port (ReadIOCompletion): Operation aborted canceled: true } +2ms serialport:main _read queueing _read for after open +2ms serialport:main binding.close finished +35ms { '0': null }

stefanpoeter commented 6 years ago

Confused Buffer.list with Buffer.concat. Musst be the sea in front of me :-) try again.

LogicNode commented 6 years ago

got this serialport:binding:auto-detect loading WindowsBinding +0ms serialport:main opening path: COM5 +0ms serialport:bindings open +0ms serialport:main _read queueing _read for after open +2ms serialport:main opened path: COM5 +87ms opened modbus-client issuing new read holding registers request +0ms rtu-client-request-handler registrating new request +0ms user-request creating new user request with timeout 5000 +0ms client-request-handler flushing +0ms client-request-handler flushing new request <Buffer 01 03 00 01 00 01 d5 ca> +2ms serialport:main _write 8 bytes of data +10ms serialport:bindings write 8 bytes +99ms serialport:main _read reading +4ms serialport:bindings read +3ms serialport:main binding.write write finished +2ms client-request-handler request fully flushed, ( error: undefined ) undefined +8ms serialport:main binding.read finished +28ms modbus-client received data +42ms rtu-response-handler receiving new data +0ms rtu-response-handler buffer <Buffer 01> +2ms rtu-response address 1 buffer <Buffer 01> +0ms response-factory when NoSuchIndex Exception, the buffer does not contain a complete message +0ms response-factory RangeError: Index out of range response-factory at checkOffset (buffer.js:977:11) response-factory at Buffer.readUInt8 (buffer.js:1015:5) response-factory at Function.fromBuffer (F:\ocnplcx\nodeapps0\node_modules\jsmodbus\src\response\response-factory.js:19:23) response-factory at Function.fromBuffer (F:\ocnplcx\nodeapps0\node_modules\jsmodbus\src\rtu-response.js:14:32) response-factory at ModbusRTUClientResponseHandler.handleData (F:\ocnplcx\nodeapps0\node_modules\jsmodbus\src\rtu-client-response-handler.js:17:40) response-factory at ModbusRTUClient._onData (F:\ocnplcx\nodeapps0\node_modules\jsmodbus\src\modbus-client.js:37:27) response-factory at emitOne (events.js:121:20) response-factory at SerialPort.emit (events.js:211:7) response-factory at addChunk (_stream_readable.js:263:12) response-factory at readableAddChunk (_stream_readable.js:250:11) +1ms rtu-response-handler not enough data available to parse +4ms { '0': <Buffer 01> } serialport:main _read reading +11ms serialport:bindings read +43ms serialport:main binding.read finished +6ms modbus-client received data +15ms rtu-response-handler receiving new data +8ms rtu-response-handler buffer <Buffer 01 03 02 00 32 39 91> +1ms rtu-response address 1 buffer <Buffer 01 03 02 00 32 39 91> +13ms response-factory fc 3 payload <Buffer 03 02 00 32 39 91> +11ms rtu-response-handler crc 259 +2ms rtu-response-handler reset buffer from 7 to 1 +0ms rtu-response address 145 buffer <Buffer 91> +2ms response-factory when NoSuchIndex Exception, the buffer does not contain a complete message +3ms response-factory RangeError: Index out of range response-factory at checkOffset (buffer.js:977:11) response-factory at Buffer.readUInt8 (buffer.js:1015:5) response-factory at Function.fromBuffer (F:\ocnplcx\nodeapps0\node_modules\jsmodbus\src\response\response-factory.js:19:23) response-factory at Function.fromBuffer (F:\ocnplcx\nodeapps0\node_modules\jsmodbus\src\rtu-response.js:14:32) response-factory at ModbusRTUClientResponseHandler.handleData (F:\ocnplcx\nodeapps0\node_modules\jsmodbus\src\rtu-client-response-handler.js:17:40) response-factory at ModbusRTUClient._onData (F:\ocnplcx\nodeapps0\node_modules\jsmodbus\src\modbus-client.js:37:27) response-factory at emitOne (events.js:121:20) response-factory at SerialPort.emit (events.js:211:7) response-factory at addChunk (_stream_readable.js:263:12) response-factory at readableAddChunk (_stream_readable.js:250:11) +2ms rtu-response-handler not enough data available to parse +4ms rtu-client-request-handler new response coming in +65ms rtu-client-request-handler create crc from response +1ms rtu-client-request-handler CRC does not match 259 !== 34049 +1ms { '0': <Buffer 03 02 00 32 39 91> } serialport:main _read reading +12ms serialport:bindings read +20ms { '0': { err: 'crcMismatch', message: 'the response payload does not match the crc' } } serialport:main #close +9ms serialport:bindings close +6ms serialport:main binding.read error { Error: Reading from COM port (ReadIOCompletion): Operation aborted canceled: true } +1ms serialport:main _read queueing _read for after open +1ms serialport:main binding.close finished +36ms { '0': null }

stefanpoeter commented 6 years ago

well that looks promising. Seems like your device is answering, slowly but still. Problem now is, the crc from the response is checked wrong, probably for the same reasons the requests crc was wrong. I'll prepare another commit soon.

stefanpoeter commented 6 years ago

Try again. The tests fail but I think it could work.

LogicNode commented 6 years ago

Test failed.

stefanpoeter commented 6 years ago

That's not a problem. I'll fix it later. You can still use it.

stefanpoeter commented 6 years ago

Did it work?

LogicNode commented 6 years ago

No, it is not working :(

stefanpoeter commented 6 years ago

I made a small patch on the holding register response. Can update your clone and post the debug messages once again?

LogicNode commented 6 years ago

F:\ocnplcx\nodeapps0>node hhr serialport:binding:auto-detect loading WindowsBinding +0ms serialport:main opening path: COM6 +0ms serialport:bindings open +0ms serialport:main _read queueing _read for after open +3ms serialport:main opened path: COM6 +85ms opened modbus-client issuing new read holding registers request +0ms rtu-client-request-handler registrating new request +0ms user-request creating new user request with timeout 5000 +0ms client-request-handler flushing +0ms client-request-handler flushing new request <Buffer 01 03 00 00 00 01 84 0a> +1ms serialport:main _write 8 bytes of data +9ms serialport:bindings write 8 bytes +98ms serialport:main _read reading +4ms serialport:bindings read +1ms serialport:main binding.write write finished +1ms client-request-handler request fully flushed, ( error: undefined ) undefined +7ms serialport:main binding.read finished +32ms modbus-client received data +43ms rtu-response-handler receiving new data +0ms rtu-response-handler buffer <Buffer 01> +1ms rtu-response address 1 buffer <Buffer 01> +0ms response-factory when NoSuchIndex Exception, the buffer does not contain a complete message +0ms response-factory RangeError: Index out of range response-factory at checkOffset (buffer.js:977:11) response-factory at Buffer.readUInt8 (buffer.js:1015:5) response-factory at Function.fromBuffer (F:\ocnplcx\nodeapps0\node_modules\jsmodbus\src\response\response-factory.js:19:23) response-factory at Function.fromBuffer (F:\ocnplcx\nodeapps0\node_modules\jsmodbus\src\rtu-response.js:14:32) response-factory at ModbusRTUClientResponseHandler.handleData (F:\ocnplcx\nodeapps0\node_modules\jsmodbus\src\rtu-client-response-handler.js:17:40) response-factory at ModbusRTUClient._onData (F:\ocnplcx\nodeapps0\node_modules\jsmodbus\src\modbus-client.js:37:27) response-factory at emitOne (events.js:121:20) response-factory at SerialPort.emit (events.js:211:7) response-factory at addChunk (_stream_readable.js:263:12) response-factory at readableAddChunk (_stream_readable.js:250:11) +1ms rtu-response-handler not enough data available to parse +4ms { '0': <Buffer 01> } serialport:main _read reading +13ms serialport:bindings read +46ms serialport:main binding.read finished +1ms modbus-client received data +13ms rtu-response-handler receiving new data +9ms rtu-response-handler buffer <Buffer 01 03 02 13 88 b5 12> +0ms rtu-response address 1 buffer <Buffer 01 03 02 13 88 b5 12> +13ms response-factory fc 3 payload <Buffer 03 02 13 88 b5 12> +12ms rtu-response-handler crc 769 +2ms rtu-response-handler reset buffer from 7 to 0 +0ms rtu-response-handler not enough data available to parse +1ms rtu-client-request-handler new response coming in +59ms rtu-client-request-handler create crc from response +1ms (node:1436) UnhandledPromiseRejectionWarning: TypeError: "value" argument is out of bounds at checkInt (buffer.js:1185:11) at Buffer.writeUInt8 (buffer.js:1233:5) at F:\ocnplcx\nodeapps0\node_modules\jsmodbus\src\response\read-holding-registers.js:87:15 at Array.forEach () at ReadHoldingRegistersResponseBody.createPayload (F:\ocnplcx\nodeapps0\node_modules\jsmodbus\src\response\read-holding-registers.js:86:18) at ModbusRTUClientRequestHandler.handle (F:\ocnplcx\nodeapps0\node_modules\jsmodbus\src\rtu-client-request-handler.js:47:93) at ModbusRTUClient._onData (F:\ocnplcx\nodeapps0\node_modules\jsmodbus\src\modbus-client.js:51:30) at emitOne (events.js:121:20) at SerialPort.emit (events.js:211:7) at addChunk (_stream_readable.js:263:12) (node:1436) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). (rejection id: 1) (node:1436) [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate the Node.js process with a non-zero exit code. client-request-handler flushing +5s client-request-handler no request to be executed +0ms { '0': { err: 'Timeout', message: 'Request timed out' } } serialport:main #close +5s serialport:bindings close +5s serialport:main binding.close finished +36ms { '0': null }

LogicNode commented 6 years ago

I think it is okay as the value polled correctly value of Register 30001 is '5000' in decimal but the values need to be printed out in console.log! Request of the above debug: 2018-06-23 23_33_29-session 11 - pulseview

Response: 2018-06-23 23_32_07-session 1 - pulseview

stefanpoeter commented 6 years ago

Great news. I'll prepare a complete patch next week.

Without knowing your code I think the attribute valueAsBuffer is what you are looking for.