steveohara / j2mod

Enhanced Modbus library implemented in the Java programming language
Apache License 2.0
276 stars 110 forks source link

Help: reading schneider PM5350, weird behavior encountered. #26

Closed axuan25 closed 8 years ago

axuan25 commented 8 years ago

I am experiencing a weird issue using J2mod to read a Schneider power meter (PM5350).

Before I got into details, I have to mention that I have so far used J2mod to read many other power meters without any issue. In fact, J2mod has been extremely helpful in our project. I have also written a fluent wrapper API around J2mod to abstract and encapsulate Serial, TCP and RTU/TCP connections (which I would love to share, but cannot at this moment, will be doing so in the future). Anyhow, J2mod has worked seamlessly until I tried to read this device. I pray that this is a mistake of mine only, and hope that you might enlighten me on what I might be doing wrong, but after two days of trying to figure this out on my own, I am beginning to suspect J2mod to be culprit. Now, onto the details:

As mentioned, I am trying to read a Schneider PM5350 power meter. Its configuration is as follows:

Modbus RTU / ASCII Baud: 9600 Parity "none" -> Databits 8, Stop bits 2 Parity "even/odd" -> Databits 8, Stop bits 1

I would like to read its frequency, of which the value is known to be 60.00 Hz (varies between 59~61). This value is big-endian floating point value stored onto two typical 16bit registers. The registers are 3110 and 3111.

When reading modbus devices, I use command line tool named "Modpoll" in conjunction with my code (j2mod 2.1.+ && jSerialComm 1.3.11) to compare values. So far, on all the devices I have previously mapped, values were the same. However, when trying to read the meter using j2mod, the returned values are always incorrect.

Using Modpoll (as demonstrated below), I am always able to read the proper values for both registers. Because it is a big-endian floating point, the value of the second register (3111) always changes, which is normal. Using an IEEE conversion sheet, I am able to compute the correct value to ~60.00.

Lastly, I have tried reading the meter (using both modpoll and j2mod) in two ways:

  1. Using a TCP to RTU converter gateway (which works neatly with other devices)
  2. Directly using RTU on /dev/ttyUSB0

The following are my tests:

MODPOLL TCP

Hex

$ ./modpoll -m tcp -a 5 -r 3110 -c 2 -t 4:hex -f 192.168.127.55

Protocol configuration: MODBUS/TCP
Slave configuration...: address = 5, start reference = 3110, count = 2
Communication.........: 192.168.127.55, port 502, t/o 1.00 s, poll rate 1000 ms
Data type.............: 16-bit register (hex), output (holding) register table
Word swapping.........: Slave configured as big-endian float machine

-- Polling slave... (Ctrl-C to stop)
[3110]: 0x4270
[3111]: 0x0A41

Dec

$ ./modpoll -m tcp -a 5 -r 3110 -c 2 -t 4 -f 192.168.127.55

Protocol configuration: MODBUS/TCP
Slave configuration...: address = 5, start reference = 3110, count = 2
Communication.........: 192.168.127.55, port 502, t/o 1.00 s, poll rate 1000 ms
Data type.............: 16-bit register, output (holding) register table
Word swapping.........: Slave configured as big-endian float machine

-- Polling slave... (Ctrl-C to stop)
[3110]: 17008
[3111]: 4781

# Float = 60.0182380676

J2MOD TCP

(not using my wrapper code for testing purposes here)

TCPMasterConnection connection = new TCPMasterConnection(InetAddress.getByName("192.168.127.55"));
connection.setPort(502);

// Build request (unit 1, register 3110, 2 words)
ReadMultipleRegistersRequest req = new ReadMultipleRegistersRequest(3110, 2);
req.setUnitID(5);

// Obtain transaction, set request
connection.connect();
ModbusTCPTransaction transaction = new ModbusTCPTransaction(connection);
//        transaction.setConnection(connection);
transaction.setRequest(req);

// Open, execute, close
transaction.execute();
ReadMultipleRegistersResponse res = (ReadMultipleRegistersResponse) transaction.getResponse();
connection.close();

// Read value

LOG.debug("Response: {} words\n>{}\n>{}\n{} + {}",
        res.getWordCount(), res.getMessage(), res.getHexMessage(),
        res.getRegisterValue(0), res.getRegisterValue(1));

Exec 1

2016-07-07 13:56:48,248 [main] DEBUG c.g.j.modbus.net.TCPMasterConnection - connect()
2016-07-07 13:56:48,254 [main] TRACE c.g.j.modbus.net.TCPMasterConnection - prepareTransport() -> using standard TCP transport.
2016-07-07 13:56:48,261 [main] DEBUG c.g.j.modbus.io.ModbusTCPTransaction - request transaction ID = 0
2016-07-07 13:56:48,265 [main] DEBUG c.g.j.modbus.io.ModbusTCPTransport - Sent: 00 00 00 00 00 06 05 03 0C 26 00 02
2016-07-07 13:56:48,266 [main] DEBUG c.g.j.modbus.io.ModbusTCPTransport - Read: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2016-07-07 13:56:48,303 [main] DEBUG c.g.j.m.io.FastByteArrayInputStream - reset()
2016-07-07 13:56:48,303 [main] DEBUG c.g.j.m.io.FastByteArrayInputStream - mark=0 pos=0
2016-07-07 13:56:48,303 [main] DEBUG c.g.j.m.io.FastByteArrayInputStream - mark()
2016-07-07 13:56:48,304 [main] DEBUG c.g.j.m.io.FastByteArrayInputStream - mark=0
2016-07-07 13:56:48,304 [main] DEBUG c.g.j.m.io.FastByteArrayInputStream - read()
2016-07-07 13:56:48,304 [main] DEBUG c.g.j.m.io.FastByteArrayInputStream - count=13
2016-07-07 13:56:48,316 [main] DEBUG c.g.j.m.io.FastByteArrayInputStream - reset()
2016-07-07 13:56:48,316 [main] DEBUG c.g.j.m.io.FastByteArrayInputStream - mark=0 pos=0
2016-07-07 13:56:48,317 [main] DEBUG c.g.j.m.io.FastByteArrayInputStream - read()
2016-07-07 13:56:48,317 [main] DEBUG c.g.j.m.io.FastByteArrayInputStream - count=13
2016-07-07 13:56:48,317 [main] DEBUG c.g.j.m.io.FastByteArrayInputStream - read()
2016-07-07 13:56:48,317 [main] DEBUG c.g.j.m.io.FastByteArrayInputStream - count=13
2016-07-07 13:56:48,317 [main] DEBUG c.g.j.m.io.FastByteArrayInputStream - read()
2016-07-07 13:56:48,317 [main] DEBUG c.g.j.m.io.FastByteArrayInputStream - count=13
2016-07-07 13:56:48,317 [main] DEBUG c.g.j.m.io.FastByteArrayInputStream - read()
2016-07-07 13:56:48,317 [main] DEBUG c.g.j.m.io.FastByteArrayInputStream - count=13
2016-07-07 13:56:48,317 [main] DEBUG c.g.j.m.io.FastByteArrayInputStream - read()
2016-07-07 13:56:48,317 [main] DEBUG c.g.j.m.io.FastByteArrayInputStream - count=13
2016-07-07 13:56:48,317 [main] DEBUG c.g.j.m.io.FastByteArrayInputStream - read()
2016-07-07 13:56:48,317 [main] DEBUG c.g.j.m.io.FastByteArrayInputStream - count=13
2016-07-07 13:56:48,318 [main] DEBUG c.g.j.m.io.FastByteArrayInputStream - read()
2016-07-07 13:56:48,318 [main] DEBUG c.g.j.m.io.FastByteArrayInputStream - count=13
2016-07-07 13:56:48,318 [main] DEBUG c.g.j.m.io.FastByteArrayInputStream - read()
2016-07-07 13:56:48,318 [main] DEBUG c.g.j.m.io.FastByteArrayInputStream - count=13
2016-07-07 13:56:48,318 [main] DEBUG c.g.j.m.io.FastByteArrayInputStream - read()
2016-07-07 13:56:48,318 [main] DEBUG c.g.j.m.io.FastByteArrayInputStream - count=13
2016-07-07 13:56:48,321 [main] DEBUG c.g.j.m.io.FastByteArrayInputStream - read()
2016-07-07 13:56:48,321 [main] DEBUG c.g.j.m.io.FastByteArrayInputStream - count=13
2016-07-07 13:56:48,321 [main] DEBUG c.g.j.m.io.FastByteArrayInputStream - read()
2016-07-07 13:56:48,321 [main] DEBUG c.g.j.m.io.FastByteArrayInputStream - count=13
2016-07-07 13:56:48,321 [main] DEBUG c.g.j.m.io.FastByteArrayInputStream - read()
2016-07-07 13:56:48,321 [main] DEBUG c.g.j.m.io.FastByteArrayInputStream - count=13
2016-07-07 13:56:48,322 [main] DEBUG c.g.j.m.io.FastByteArrayInputStream - read()
2016-07-07 13:56:48,323 [main] DEBUG c.g.j.m.io.FastByteArrayInputStream - count=13
2016-07-07 13:56:48,323 [main] DEBUG c.g.j.modbus.io.ModbusTCPTransaction - response transaction ID = 0, RESPONSE: 00 00 00 00 00 07 05 03 04 12 1C FF FF 
2016-07-07 13:56:48,325 [main] DEBUG c.x.modbus.schneider.SimpleReadTest - Response: 2 words
>[4, 18, 28, -1, -1]
>00 00 00 00 00 07 05 03 04 12 1C FF FF 
4636 + 65535

Exec 2

2016-07-07 13:58:23,404 [main] DEBUG c.g.j.modbus.io.ModbusTCPTransport - Sent: 00 00 00 00 00 06 05 03 0C 26 00 02
2016-07-07 13:58:23,411 [main] DEBUG c.g.j.modbus.io.ModbusTCPTransport - Read: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2016-07-07 13:58:23,459 [main] DEBUG c.g.j.modbus.io.ModbusTCPTransaction - response transaction ID = 0, RESPONSE: 00 00 00 00 00 07 05 03 04 FD 2F FF FF 
// (skip FastByteArrayInputStream debug)
2016-07-07 13:58:23,462 [main] DEBUG c.x.modbus.schneider.SimpleReadTest - Response: 2 words
>[4, -3, 47, -1, -1]
>00 00 00 00 00 07 05 03 04 FD 2F FF FF 
64815 + 65535

Now back to Modpoll, using direct RTU on /dev/ttyUSB0.

MODPOLL RTU

$ ./modpoll -m rtu -a 5 -r 3110 -c 2 -t 4 -f -b 9600 -d 8 -s 2 -p none /dev/ttyUSB0

Protocol configuration: Modbus RTU
Slave configuration...: address = 5, start reference = 3110, count = 2
Communication.........: /dev/ttyUSB0, 9600, 8, 2, none, t/o 1.00 s, poll rate 1000 ms
Data type.............: 16-bit register, output (holding) register table
Word swapping.........: Slave configured as big-endian float machine

-- Polling slave... (Ctrl-C to stop)
[3110]: 17008
[3111]: 7826
-- Polling slave... (Ctrl-C to stop)
[3110]: 17008
[3111]: 3756

$ ./modpoll -m rtu -a 5 -r 3110 -c 2 -t 4:hex -f -b 9600 -d 8 -s 2 -p none /dev/ttyUSB0

Slave configuration...: address = 5, start reference = 3110, count = 2
Communication.........: /dev/ttyUSB0, 9600, 8, 2, none, t/o 1.00 s, poll rate 1000 ms
Data type.............: 16-bit register (hex), output (holding) register table
Word swapping.........: Slave configured as big-endian float machine

-- Polling slave... (Ctrl-C to stop)
[3110]: 0x426F
[3111]: 0xFC67
-- Polling slave... (Ctrl-C to stop)
[3110]: 0x426F
[3111]: 0xF642

# Float = 60.0143280029

J2MOD RTU

(not using my wrapper code for testing purposes here)

// Build connection
SerialParameters connectionParameters;
connectionParameters = new SerialParameters();
connectionParameters.setPortName("/dev/ttyUSB0");
connectionParameters.setBaudRate(9600);
connectionParameters.setDatabits(8);
connectionParameters.setParity("none");
connectionParameters.setStopbits(2);
connectionParameters.setEncoding(Modbus.SERIAL_ENCODING_RTU);
SerialConnection connection = new SerialConnection(connectionParameters);

// Build request (unit 5, register 3110, 2 words)
ReadMultipleRegistersRequest req = new ReadMultipleRegistersRequest(3110, 2);
req.setUnitID(5);

// Open connection, obtain transaction, set request
connection.open();
ModbusSerialTransaction transaction = new ModbusSerialTransaction(connection);
transaction.setRequest(req);

// Execute, close
transaction.execute();
connection.close();

// Read value
ReadMultipleRegistersResponse res = (ReadMultipleRegistersResponse) transaction.getResponse();

LOG.debug("Response: {} words\n>{}\n>{}\n{} + {}",
        res.getWordCount(), res.getMessage(), res.getHexMessage(),
        res.getRegisterValue(0), res.getRegisterValue(1));

Exec 1

2016-07-07 14:10:13,540 [main] DEBUG c.g.j.modbus.io.ModbusRTUTransport - Sent: 05 03 0C 26 00 02 27 14 
2016-07-07 14:10:13,586 [main] DEBUG c.g.j.modbus.io.ModbusRTUTransport - Response: 05 03 04 F1 33 FF FF 7C B0 
2016-07-07 14:10:13,586 [main] DEBUG c.g.j.m.io.FastByteArrayInputStream - read()
2016-07-07 14:10:13,586 [main] DEBUG c.g.j.m.io.FastByteArrayInputStream - count=7
2016-07-07 14:10:13,586 [main] DEBUG c.g.j.m.io.FastByteArrayInputStream - read()
2016-07-07 14:10:13,586 [main] DEBUG c.g.j.m.io.FastByteArrayInputStream - count=7
2016-07-07 14:10:13,587 [main] DEBUG c.g.j.m.io.FastByteArrayInputStream - read()
2016-07-07 14:10:13,587 [main] DEBUG c.g.j.m.io.FastByteArrayInputStream - count=7
2016-07-07 14:10:13,593 [main] DEBUG c.g.j.m.io.FastByteArrayInputStream - read()
2016-07-07 14:10:13,597 [main] DEBUG c.g.j.m.io.FastByteArrayInputStream - count=7
2016-07-07 14:10:13,598 [main] DEBUG c.g.j.m.io.FastByteArrayInputStream - read()
2016-07-07 14:10:13,599 [main] DEBUG c.g.j.m.io.FastByteArrayInputStream - count=7
2016-07-07 14:10:13,599 [main] DEBUG c.g.j.m.io.FastByteArrayInputStream - read()
2016-07-07 14:10:13,599 [main] DEBUG c.g.j.m.io.FastByteArrayInputStream - count=7
2016-07-07 14:10:13,602 [main] DEBUG c.g.j.m.io.FastByteArrayInputStream - read()
2016-07-07 14:10:13,604 [main] DEBUG c.g.j.m.io.FastByteArrayInputStream - count=7
2016-07-07 14:10:13,610 [main] DEBUG c.x.modbus.schneider.SimpleReadTest - Response: 2 words
>[4, -15, 51, -1, -1]
>05 03 04 F1 33 FF FF 
61747 + 65535

Exec 2

2016-07-07 14:10:45,401 [main] DEBUG c.g.j.modbus.io.ModbusRTUTransport - Sent: 05 03 0C 26 00 02 27 14 
2016-07-07 14:10:45,456 [main] DEBUG c.g.j.modbus.io.ModbusRTUTransport - Response: 05 03 04 1D 1B FF FF C8 28 
// (skip FastByteArrayInputStream debug)
2016-07-07 14:10:45,484 [main] DEBUG c.x.modbus.schneider.SimpleReadTest - Response: 2 words
>[4, 29, 27, -1, -1]
>05 03 04 1D 1B FF FF 
7451 + 65535

I intend to parse the float value using the following code, but as you can see, register 3111 (word 2) is always "FF FF", and even the first word does not seem correct when compared to Modpoll's output.

public static float getFloat(Register mostSignificantWord, Register leastSignificantWord) {
    if (mostSignificantWord == null || leastSignificantWord == null) throw new NullPointerException();

    byte[] array = new byte[4];
    array[0] = mostSignificantWord.toBytes()[0];
    array[1] = mostSignificantWord.toBytes()[1];
    array[2] = leastSignificantWord.toBytes()[0];
    array[3] = leastSignificantWord.toBytes()[1];

    ByteBuffer bb = ByteBuffer.wrap(array);
    return bb.getFloat();
}

I must say I am not a Modbus expert, and am self-taught in the art of computer science. I am looking forward to your input and am eager to learn where I might be mistaken. Otherwise, it sounds like a bug candidate!

Last note: because the Schneider meter modbus settings are configurable, I have played around and tried with different parity, and even using ASCII, but to no avail.

Best regards, Christopher

steveohara commented 8 years ago

Hey Christopher, I can't see anything obvious. I assume you get the same result using the latest v2.2.0 version? BTW, you might find using ModbusSerialMaster a little easier on the eye code wise.

axuan25 commented 8 years ago

Yes, I was just playing around with different settings etc, trying to figure this out. Also yes, version 2.2.0 gives me the same response. I will be trying again with j2mod 1.x using RxTx, just to see (it did seem to be slightly faster too), once back at the office. If you have any suggestions as to other ways to debug this, I would highly appreciate that! Otherwise, I will keep this ticket up to date with my progress.

Best,

axuan25 commented 8 years ago

It's a good idea to take a break off debugging stuff sometimes. Today I tried again and decided to try something simple: what if the references start at 0, instead of 1? Surprise surprise, I could read my IEEE floating point! It didn't help that Schneider's documentation fails to mention this.

If using j2mod to read Schneider 5350, one needs to subtract 1 from each references (ref 3110 -> 3109).

Hopefully this thread can be of use to others in the future.