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

Not restore alfer line fault (dev 1.3.2) #188

Closed
wants to merge 295 commits into from

Conversation

krip-tip
Copy link

@krip-tip krip-tip commented Jul 3, 2017

After a failure in the line (com-port), communication is not restored.
If you clear the buffer before calling the exception - everything works

bashwork and others added 30 commits November 20, 2011 18:43
Fixes a TypeError occuring while escaping token bytes in the message and
adds the start and end tokens to the packet.
Fix binary framer and add start and end tokens
* Now correctly decoding sub function messages (diagnostic)
* Message parser now finished and documented
* Fixed broken logger unit test
ModbusSparseDataBlock handled dictionaries incorrectly (they have an __i...
@dhoomakethu dhoomakethu mentioned this pull request Aug 24, 2017
21 tasks
@ccatterina
Copy link
Contributor

Yes, i'm using the version 1.3.2 released yesterday.

I don't know exactly how to reproduce it, it's probably related to the noises on the serial line, it happens after 5-10 minutes of continuous readings and only with devices that frequently reply with wrong data (for example 0xff 0xff 0xff 0xff 0xff 0xff in the last recv before the error).

@dhoomakethu
Copy link
Contributor

@oleg-krv and @ccatterina Are you guys still having this issue ? Could you guys please give a try on the latest on dev branch and see if that addresses the issue in this PR?

@dhoomakethu dhoomakethu added this to the 2.0.0 milestone Dec 23, 2017
@dhoomakethu dhoomakethu mentioned this pull request Dec 23, 2017
12 tasks
@ccatterina
Copy link
Contributor

hi @dhoomakethu , i just tried the dev branch and i still experience the same issue:

  File "build/bdist.linux-armv7l/egg/pymodbus/client/common.py", line 109, in read_holding_registers
    return self.execute(request)
  File "build/bdist.linux-armv7l/egg/pymodbus/client/sync.py", line 85, in execute
    return self.transaction.execute(request)
  File "build/bdist.linux-armv7l/egg/pymodbus/transaction.py", line 143, in execute
    self.client.framer.processIncomingPacket(result, self.addTransaction)
  File "build/bdist.linux-armv7l/egg/pymodbus/transaction.py", line 709, in processIncomingPacket
    self._process(callback, error=True)
  File "build/bdist.linux-armv7l/egg/pymodbus/transaction.py", line 729, in _process
    result = self.decoder.decode(data)
  File "build/bdist.linux-armv7l/egg/pymodbus/factory.py", line 223, in decode
    return self._helper(message)
  File "build/bdist.linux-armv7l/egg/pymodbus/factory.py", line 245, in _helper
    response.decode(data[1:])
  File "build/bdist.linux-armv7l/egg/pymodbus/pdu.py", line 192, in decode
    self.exception_code = byte2int(data[0])
IndexError: string index out of range

@dhoomakethu
Copy link
Contributor

@ccatterina are you observing this against a real device ? Could you share the details ?

@ccatterina
Copy link
Contributor

ccatterina commented Jan 26, 2018

yes, i'm trying to read 30 photovoltaic string subcombiners, the error appear after about 30-60 sec of continuous read, the line is noisy and the devices responses sometimes are invalid.

Here's the last part of the log with debug enabled:

DEBUG:pymodbus.transaction:Transaction failed. (timed out) 
DEBUG:pymodbus.transaction:send: 0x9 0x3 0x0 0xde 0x0 0x1 0xe5 0x78
DEBUG:pymodbus.transaction:Transaction failed. (timed out) 
DEBUG:pymodbus.transaction:getting transaction 1
[26/Jan/2018 11:24:34] ERROR [api.reader:88] ['string_boxes_area_1':'string_box_1_1_1']Error reading register `voltage': `Modbus Error: [Input/Output] timed out'
DEBUG:pymodbus.transaction:Running transaction 1
DEBUG:pymodbus.transaction:send: 0x2 0x3 0x3 0xe8 0x0 0x1 0x4 0x49
DEBUG:pymodbus.transaction:Expected - 7 bytes, Actual - 1 bytes
DEBUG:pymodbus.transaction:recv: 0x2 0x3 0x2 0x2 0x5a 0x7d 0x1f
DEBUG:pymodbus.factory:Factory Response[3]
DEBUG:pymodbus.transaction:adding transaction 0
DEBUG:pymodbus.transaction:getting transaction 1
DEBUG:pymodbus.transaction:Running transaction 2
DEBUG:pymodbus.transaction:send: 0x2 0x3 0x3 0xe9 0x0 0x1 0x55 0x89
DEBUG:pymodbus.transaction:recv: 0x2 0x3 0x2 0x18 0x7e 0x76 0x64
DEBUG:pymodbus.factory:Factory Response[3]
DEBUG:pymodbus.transaction:adding transaction 0
DEBUG:pymodbus.transaction:getting transaction 2
DEBUG:pymodbus.transaction:Running transaction 3
DEBUG:pymodbus.transaction:send: 0x2 0x3 0x3 0xeb 0x0 0x2 0xb4 0x48
DEBUG:pymodbus.transaction:recv: 0x2 0x3 0x4 0xb1 0xf8 0x0 0x5 0xaf 0xfd
DEBUG:pymodbus.factory:Factory Response[3]
DEBUG:pymodbus.transaction:adding transaction 0
DEBUG:pymodbus.transaction:getting transaction 3
DEBUG:pymodbus.transaction:Running transaction 4
DEBUG:pymodbus.transaction:send: 0x2 0x3 0x5 0x14 0x0 0x1 0xc4 0xf1
DEBUG:pymodbus.transaction:recv: 0x2 0x3 0x2 0x0 0x41 0x3c 0x74
DEBUG:pymodbus.factory:Factory Response[3]
DEBUG:pymodbus.transaction:adding transaction 0
DEBUG:pymodbus.transaction:getting transaction 4
DEBUG:pymodbus.transaction:Running transaction 5
DEBUG:pymodbus.transaction:send: 0x2 0x3 0x4 0x4c 0x0 0x1 0x44 0xde
DEBUG:pymodbus.transaction:recv: 0x2 0x3 0x2 0x2 0x5a 0x7d 0x1f
DEBUG:pymodbus.factory:Factory Response[3]
DEBUG:pymodbus.transaction:adding transaction 0
DEBUG:pymodbus.transaction:getting transaction 5
DEBUG:pymodbus.transaction:Running transaction 6
DEBUG:pymodbus.transaction:send: 0x2 0x3 0x5 0x15 0x0 0x1 0x95 0x31
DEBUG:pymodbus.transaction:recv: 0x2 0x3 0x2 0x0 0x3c 0xfc 0x55
DEBUG:pymodbus.factory:Factory Response[3]
DEBUG:pymodbus.transaction:adding transaction 0
DEBUG:pymodbus.transaction:getting transaction 6
DEBUG:pymodbus.transaction:Running transaction 7
DEBUG:pymodbus.transaction:send: 0x2 0x3 0x4 0x4d 0x0 0x1 0x15 0x1e
DEBUG:pymodbus.transaction:recv: 0x2 0x3 0x2 0x2 0x5a 0x7d 0x1f
DEBUG:pymodbus.factory:Factory Response[3]
DEBUG:pymodbus.transaction:adding transaction 0
DEBUG:pymodbus.transaction:getting transaction 7
DEBUG:pymodbus.transaction:Running transaction 8
DEBUG:pymodbus.transaction:send: 0x2 0x3 0x5 0x16 0x0 0x1 0x65 0x31
DEBUG:pymodbus.transaction:Expected - 7 bytes, Actual - 1 bytes
DEBUG:pymodbus.transaction:Transaction failed. (timed out) 
DEBUG:pymodbus.transaction:send: 0x19 0x3 0x3 0xe8 0x0 0x1 0x7 0xa2
DEBUG:pymodbus.transaction:recv: 0xff
DEBUG:pymodbus.factory:Factory Response[255]
[26/Jan/2018 11:24:36] CRITICAL [api.reader:68] Thread Exception: Traceback (most recent call last):
  File "/opt/eva-plants-api/api/management/commands/reader.py", line 38, in _function_wrapper
    return fn(*args, **kwargs)
  File "/opt/eva-plants-api/api/management/commands/reader.py", line 86, in run
    device.read()
  File "/opt/eva-plants-api/api/app/device/device.py", line 228, in read
    temp_registers_list[idx] = self.read_register(register)
  File "/opt/eva-plants-api/api/app/device/device.py", line 260, in read_register
    return protocol.read(register)
  File "/opt/eva-plants-api/api/app/protocols/modbus_rtu_over_tcp.py", line 35, in read
    return self.modbus.read(register)
  File "/opt/eva-plants-api/api/app/protocols/lib/modbus.py", line 95, in read
    data = self.client.read_holding_registers(*args, **kwargs)
  File "build/bdist.linux-armv7l/egg/pymodbus/client/common.py", line 109, in read_holding_registers
    return self.execute(request)
  File "build/bdist.linux-armv7l/egg/pymodbus/client/sync.py", line 85, in execute
    return self.transaction.execute(request)
  File "build/bdist.linux-armv7l/egg/pymodbus/transaction.py", line 143, in execute
    self.client.framer.processIncomingPacket(result, self.addTransaction)
  File "build/bdist.linux-armv7l/egg/pymodbus/transaction.py", line 709, in processIncomingPacket
    self._process(callback, error=True)
  File "build/bdist.linux-armv7l/egg/pymodbus/transaction.py", line 729, in _process
    result = self.decoder.decode(data)
  File "build/bdist.linux-armv7l/egg/pymodbus/factory.py", line 223, in decode
    return self._helper(message)
  File "build/bdist.linux-armv7l/egg/pymodbus/factory.py", line 245, in _helper
    response.decode(data[1:])
  File "build/bdist.linux-armv7l/egg/pymodbus/pdu.py", line 192, in decode
    self.exception_code = byte2int(data[0])
IndexError: string index out of range

[26/Jan/2018 11:24:36] CRITICAL [api.reader:69] Exiting because a reader daemon is dead!

dhoomakethu added a commit that referenced this pull request Jan 26, 2018
@dhoomakethu
Copy link
Contributor

@ccatterina Thanks, Please give this branch a try.

@ccatterina
Copy link
Contributor

ccatterina commented Jan 29, 2018

Unfortunately I have found the same issue in redo-modbus-serial-transaction branch.

@dhoomakethu
Copy link
Contributor

@ccatterina thanks, could you please share the logs? Also if you this PR , is it fixing the issue?

@ccatterina
Copy link
Contributor

Here's the log with redo-modbus-serial-transaction branch:

...
DEBUG:pymodbus.transaction:Getting transaction 43
DEBUG:pymodbus.transaction:Running transaction 44
DEBUG:pymodbus.transaction:SEND: 0x3b 0x3 0x4 0x54 0x0 0x1 0xc1 0xb0
DEBUG:pymodbus.transaction:RECV: 0x13 0x3 0x2 0x0 0x1e 0x80 0x4f
DEBUG:pymodbus.transaction:Getting Frame - 0x3 0x2 0x0 0x1e
DEBUG:pymodbus.factory:Factory Response[3]
DEBUG:pymodbus.transaction:Running transaction 46
DEBUG:pymodbus.transaction:Frame advanced, resetting header!!
DEBUG:pymodbus.transaction:SEND: 0x0 0x2e 0x0 0x0 0x0 0x6 0x0 0x4 0x0 0x30 0x0 0x2
DEBUG:pymodbus.transaction:Adding transaction 0
DEBUG:pymodbus.transaction:Getting transaction 27
DEBUG:pymodbus.transaction:Running transaction 28
DEBUG:pymodbus.transaction:SEND: 0x13 0x3 0x4 0x4d 0x0 0x1 0x16 0x5f
DEBUG:pymodbus.transaction:RECV: 0x0 0x2e 0x0 0x0 0x0 0x7 0x0 0x4 0x4 0x0 0x1 0x7c 0xdc
DEBUG:pymodbus.transaction:Processing: 0x0 0x2e 0x0 0x0 0x0 0x7 0x0 0x4 0x4 0x0 0x1 0x7c 0xdc
DEBUG:pymodbus.factory:Factory Response[4]
DEBUG:pymodbus.transaction:Adding transaction 46
DEBUG:pymodbus.transaction:Getting transaction 46
DEBUG:pymodbus.transaction:RECV: 0x3b 0x3 0x2 0x2 0x71 0xa1 0x5
DEBUG:pymodbus.transaction:Getting Frame - 0x3 0x2 0x2 0x71
DEBUG:pymodbus.factory:Factory Response[3]
DEBUG:pymodbus.transaction:Frame advanced, resetting header!!
DEBUG:pymodbus.transaction:Adding transaction 0
DEBUG:pymodbus.transaction:Getting transaction 44
DEBUG:pymodbus.transaction:Running transaction 45
DEBUG:pymodbus.transaction:SEND: 0x3b 0x3 0x5 0x1d 0x0 0x1 0x11 0x9a
DEBUG:pymodbus.transaction:RECV: 0x13 0x3 0x2 0x2 0x3e 0x80 0xf7
DEBUG:pymodbus.transaction:Getting Frame - 0x3 0x2 0x2 0x3e
DEBUG:pymodbus.transaction:Running transaction 47
DEBUG:pymodbus.factory:Factory Response[3]
DEBUG:pymodbus.transaction:SEND: 0x0 0x2f 0x0 0x0 0x0 0x6 0x0 0x4 0x0 0x38 0x0 0x2
DEBUG:pymodbus.transaction:Frame advanced, resetting header!!
DEBUG:pymodbus.transaction:Adding transaction 0
DEBUG:pymodbus.transaction:Getting transaction 28
DEBUG:pymodbus.transaction:Running transaction 29
DEBUG:pymodbus.transaction:SEND: 0x13 0x3 0x5 0x16 0x0 0x1 0x66 0x70
DEBUG:pymodbus.transaction:RECV: 0x3b 0x3 0x2 0x0 0x1c 0x61 0x88
DEBUG:pymodbus.transaction:Getting Frame - 0x3 0x2 0x0 0x1c
DEBUG:pymodbus.factory:Factory Response[3]
DEBUG:pymodbus.transaction:Frame advanced, resetting header!!
DEBUG:pymodbus.transaction:Adding transaction 0
DEBUG:pymodbus.transaction:Getting transaction 45
DEBUG:pymodbus.transaction:Running transaction 46
DEBUG:pymodbus.transaction:SEND: 0x3b 0x3 0x4 0x55 0x0 0x1 0x90 0x70
DEBUG:pymodbus.transaction:RECV: 0x0 0x2f 0x0 0x0 0x0 0x7 0x0 0x4 0x4 0x0 0x0 0xc3 0x7b
DEBUG:pymodbus.transaction:Processing: 0x0 0x2f 0x0 0x0 0x0 0x7 0x0 0x4 0x4 0x0 0x0 0xc3 0x7b
DEBUG:pymodbus.transaction:RECV: 0x13 0x3 0x2 0x0 0x1c 0x1 0x8e
DEBUG:pymodbus.factory:Factory Response[4]
DEBUG:pymodbus.transaction:Getting Frame - 0x3 0x2 0x0 0x1c
DEBUG:pymodbus.transaction:Adding transaction 47
DEBUG:pymodbus.factory:Factory Response[3]
DEBUG:pymodbus.transaction:Running transaction 5
DEBUG:pymodbus.transaction:Getting transaction 47
DEBUG:pymodbus.transaction:SEND: 0x4 0x3 0x0 0xde 0x0 0x1 0xe4 0x65
DEBUG:pymodbus.transaction:Frame advanced, resetting header!!
DEBUG:pymodbus.transaction:Incomplete message received, Expected 7 bytes Recieved 1 bytes !!!!
DEBUG:pymodbus.transaction:RECV: 0xff
DEBUG:pymodbus.transaction:Getting Raw Frame - �
DEBUG:pymodbus.factory:Factory Response[255]
ERROR:pymodbus.transaction:string index out of range
Traceback (most recent call last):
  File "build/bdist.linux-armv7l/egg/pymodbus/transaction.py", line 165, in execute
    self.addTransaction)
  File "build/bdist.linux-armv7l/egg/pymodbus/transaction.py", line 778, in processIncomingPacket
    self._process(callback, error=True)
  File "build/bdist.linux-armv7l/egg/pymodbus/transaction.py", line 798, in _process
    result = self.decoder.decode(data)
  File "build/bdist.linux-armv7l/egg/pymodbus/factory.py", line 223, in decode
    return self._helper(message)
  File "build/bdist.linux-armv7l/egg/pymodbus/factory.py", line 245, in _helper
    response.decode(data[1:])
  File "build/bdist.linux-armv7l/egg/pymodbus/pdu.py", line 192, in decode
    self.exception_code = byte2int(data[0])
IndexError: string index out of range
DEBUG:pymodbus.transaction:Adding transaction 0
DEBUG:pymodbus.transaction:Getting transaction 29
DEBUG:pymodbus.transaction:Running transaction 48
DEBUG:pymodbus.transaction:SEND: 0x0 0x30 0x0 0x0 0x0 0x6 0x0 0x2 0x0 0xc 0x0 0x1
DEBUG:pymodbus.transaction:Running transaction 30
DEBUG:pymodbus.transaction:SEND: 0x13 0x3 0x4 0x4e 0x0 0x1 0xe6 0x5f
[29/Jan/2018 11:29:44] CRITICAL [api.reader:68] Thread Exception: Traceback (most recent call last):
  File "/opt/eva-plants-api/api/management/commands/reader.py", line 38, in _function_wrapper
    return fn(*args, **kwargs)
  File "/opt/eva-plants-api/api/management/commands/reader.py", line 86, in run
    device.read()
  File "/opt/eva-plants-api/api/app/device/device.py", line 228, in read
    temp_registers_list[idx] = self.read_register(register)
  File "/opt/eva-plants-api/api/app/device/device.py", line 260, in read_register
    return protocol.read(register)
  File "/opt/eva-plants-api/api/app/protocols/modbus_rtu_over_tcp.py", line 35, in read
    return self.modbus.read(register)
  File "/opt/eva-plants-api/api/app/protocols/lib/modbus.py", line 93, in read
    data = self.client.read_holding_registers(*args, **kwargs)
  File "build/bdist.linux-armv7l/egg/pymodbus/client/common.py", line 122, in read_holding_registers
    return self.execute(request)
  File "build/bdist.linux-armv7l/egg/pymodbus/client/sync.py", line 97, in execute
    return self.transaction.execute(request)
  File "build/bdist.linux-armv7l/egg/pymodbus/transaction.py", line 165, in execute
    self.addTransaction)
  File "build/bdist.linux-armv7l/egg/pymodbus/transaction.py", line 778, in processIncomingPacket
    self._process(callback, error=True)
  File "build/bdist.linux-armv7l/egg/pymodbus/transaction.py", line 798, in _process
    result = self.decoder.decode(data)
  File "build/bdist.linux-armv7l/egg/pymodbus/factory.py", line 223, in decode
    return self._helper(message)
  File "build/bdist.linux-armv7l/egg/pymodbus/factory.py", line 245, in _helper
    response.decode(data[1:])
  File "build/bdist.linux-armv7l/egg/pymodbus/pdu.py", line 192, in decode
    self.exception_code = byte2int(data[0])
IndexError: string index out of range

[29/Jan/2018 11:29:44] CRITICAL [api.reader:69] Exiting because a reader daemon is dead!

Now i try with this PR.

@ccatterina
Copy link
Contributor

ccatterina commented Jan 29, 2018

i attach also the log running my reader in a single process instead of multiple threads:

[29/Jan/2018 11:37:17] INFO [api.reader:98] ['solar_meters':'inverter_2_3'] Data saved and cached.
DEBUG:pymodbus.transaction:Running transaction 2
DEBUG:pymodbus.transaction:SEND: 0x4 0x3 0x0 0xde 0x0 0x1 0xe4 0x65
DEBUG:pymodbus.transaction:Incomplete message received, Expected 5 bytes Recieved 3 bytes !!!!
DEBUG:pymodbus.transaction:RECV: 0xff 0xff 0xff
DEBUG:pymodbus.transaction:Getting Raw Frame - ���
DEBUG:pymodbus.factory:Factory Response[255]
DEBUG:pymodbus.transaction:Frame advanced, resetting header!!
DEBUG:pymodbus.transaction:Adding transaction 0
DEBUG:pymodbus.transaction:Getting transaction 2
[29/Jan/2018 11:37:17] ERROR [api.reader:91] ['solar_meters':'inverter_1_4']'dc_voltage' reading has returned Exception Response(255, 127, None)
DEBUG:pymodbus.transaction:Running transaction 2
DEBUG:pymodbus.transaction:SEND: 0x5 0x3 0x0 0xde 0x0 0x1 0xe5 0xb4
DEBUG:pymodbus.transaction:Transaction failed. (timed out) 
DEBUG:pymodbus.transaction:Getting transaction 2
[29/Jan/2018 11:37:20] ERROR [api.reader:91] ['solar_meters':'inverter_1_5']Error reading register `dc_voltage': `Modbus Error: [Input/Output] timed out'
DEBUG:pymodbus.transaction:Running transaction 9
DEBUG:pymodbus.transaction:Clearing current Frame : - 0x1 0x40 0x60 0x47 0xf9 0xe6
DEBUG:pymodbus.transaction:Resetting frame - Current Frame in buffer - 0x1 0x40 0x60 0x47 0xf9 0xe6
DEBUG:pymodbus.transaction:SEND: 0x1 0x3 0x0 0xde 0x0 0x1 0xe4 0x30
DEBUG:pymodbus.transaction:Incomplete message received, Expected 7 bytes Recieved 6 bytes !!!!
DEBUG:pymodbus.transaction:RECV: 0xc0 0x40 0x60 0xc8 0x33 0xe6
DEBUG:pymodbus.transaction:Getting Raw Frame - �@`�3�
DEBUG:pymodbus.factory:Factory Response[192]
DEBUG:pymodbus.transaction:Frame advanced, resetting header!!
DEBUG:pymodbus.transaction:Adding transaction 0
DEBUG:pymodbus.transaction:Getting Raw Frame - �
DEBUG:pymodbus.factory:Factory Response[230]
ERROR:pymodbus.transaction:string index out of range
Traceback (most recent call last):
  File "build/bdist.linux-armv7l/egg/pymodbus/transaction.py", line 165, in execute
    self.addTransaction)
  File "build/bdist.linux-armv7l/egg/pymodbus/transaction.py", line 778, in processIncomingPacket
    self._process(callback, error=True)
  File "build/bdist.linux-armv7l/egg/pymodbus/transaction.py", line 798, in _process
    result = self.decoder.decode(data)
  File "build/bdist.linux-armv7l/egg/pymodbus/factory.py", line 223, in decode
    return self._helper(message)
  File "build/bdist.linux-armv7l/egg/pymodbus/factory.py", line 245, in _helper
    response.decode(data[1:])
  File "build/bdist.linux-armv7l/egg/pymodbus/pdu.py", line 192, in decode
    self.exception_code = byte2int(data[0])
IndexError: string index out of range
Traceback (most recent call last):
  File "./manage.py", line 11, in <module>
    execute_from_command_line(sys.argv)
  File "/usr/local/lib/python2.7/dist-packages/django/core/management/__init__.py", line 363, in execute_from_command_line
    utility.execute()
  File "/usr/local/lib/python2.7/dist-packages/django/core/management/__init__.py", line 355, in execute
    self.fetch_command(subcommand).run_from_argv(self.argv)
  File "/usr/local/lib/python2.7/dist-packages/django/core/management/base.py", line 283, in run_from_argv
    self.execute(*args, **cmd_options)
  File "/usr/local/lib/python2.7/dist-packages/django/core/management/base.py", line 330, in execute
    output = self.handle(*args, **options)
  File "/opt/eva-plants-api/api/management/commands/reader.py", line 73, in handle
    self.run(groups[0].name, groups[0].sleep, groups[0].devices)        
  File "/opt/eva-plants-api/api/management/commands/reader.py", line 89, in run
    device.read()
  File "/opt/eva-plants-api/api/app/device/device.py", line 228, in read
    temp_registers_list[idx] = self.read_register(register)
  File "/opt/eva-plants-api/api/app/device/device.py", line 260, in read_register
    return protocol.read(register)
  File "/opt/eva-plants-api/api/app/protocols/modbus_rtu_over_tcp.py", line 35, in read
    return self.modbus.read(register)
  File "/opt/eva-plants-api/api/app/protocols/lib/modbus.py", line 93, in read
    data = self.client.read_holding_registers(*args, **kwargs)
  File "build/bdist.linux-armv7l/egg/pymodbus/client/common.py", line 122, in read_holding_registers
  File "build/bdist.linux-armv7l/egg/pymodbus/client/sync.py", line 97, in execute
  File "build/bdist.linux-armv7l/egg/pymodbus/transaction.py", line 165, in execute
  File "build/bdist.linux-armv7l/egg/pymodbus/transaction.py", line 778, in processIncomingPacket
  File "build/bdist.linux-armv7l/egg/pymodbus/transaction.py", line 798, in _process
  File "build/bdist.linux-armv7l/egg/pymodbus/factory.py", line 223, in decode
  File "build/bdist.linux-armv7l/egg/pymodbus/factory.py", line 245, in _helper
  File "build/bdist.linux-armv7l/egg/pymodbus/pdu.py", line 192, in decode
IndexError: string index out of range

@ccatterina
Copy link
Contributor

Also with @oleg-krv version the same exception is raised.

DEBUG:pymodbus.transaction:Running transaction 1
DEBUG:pymodbus.transaction:send: 0x64 0x3 0x0 0x4 0x0 0x2 0x8c 0x3f
DEBUG:pymodbus.transaction:Running transaction 1
DEBUG:pymodbus.transaction:send: 0x4 0x3 0x0 0xde 0x0 0x1 0xe4 0x65
DEBUG:pymodbus.transaction:recv: 0xff 0xff 0xff 0xff 0xff 0xff 0xff
DEBUG:pymodbus.transaction:Running transaction 1
DEBUG:pymodbus.transaction:send: 0x6 0x3 0x0 0xde 0x0 0x1 0xe5 0x87
DEBUG:pymodbus.transaction:Running transaction 1
DEBUG:pymodbus.transaction:send: 0xd 0x3 0x0 0xde 0x0 0x1 0xe4 0xfc
DEBUG:pymodbus.transaction:Running transaction 1
DEBUG:pymodbus.transaction:send: 0x14 0x3 0x3 0xe8 0x0 0x1 0x6 0xbf
DEBUG:pymodbus.transaction:Running transaction 1
DEBUG:pymodbus.transaction:send: 0x1b 0x3 0x3 0xe8 0x0 0x1 0x6 0x40
DEBUG:pymodbus.transaction:Running transaction 1
DEBUG:pymodbus.transaction:send: 0x39 0x3 0x3 0xe8 0x0 0x1 0x0 0xc2
DEBUG:pymodbus.transaction:recv: 0xe 0x20 0x40 0xc 0x3 0x0 0x2
[29/Jan/2018 11:58:28] CRITICAL [api.reader:68] Thread Exception: Traceback (most recent call last):
  File "/opt/eva-plants-api/api/management/commands/reader.py", line 38, in _function_wrapper
    return fn(*args, **kwargs)
  File "/opt/eva-plants-api/api/management/commands/reader.py", line 86, in run
    device.read()
  File "/opt/eva-plants-api/api/app/device/device.py", line 228, in read
    temp_registers_list[idx] = self.read_register(register)
  File "/opt/eva-plants-api/api/app/device/device.py", line 260, in read_register
    return protocol.read(register)
  File "/opt/eva-plants-api/api/app/protocols/modbus_rtu_over_tcp.py", line 35, in read
    return self.modbus.read(register)
  File "/opt/eva-plants-api/api/app/protocols/lib/modbus.py", line 93, in read
    data = self.client.read_holding_registers(*args, **kwargs)
  File "build/bdist.linux-armv7l/egg/pymodbus/client/common.py", line 109, in read_holding_registers
    return self.execute(request)
  File "build/bdist.linux-armv7l/egg/pymodbus/client/sync.py", line 85, in execute
    return self.transaction.execute(request)
  File "build/bdist.linux-armv7l/egg/pymodbus/transaction.py", line 149, in execute
    self.client.framer.processIncomingPacket(result, self.addTransaction)
  File "build/bdist.linux-armv7l/egg/pymodbus/transaction.py", line 667, in processIncomingPacket
    self._process(callback, error=True)
  File "build/bdist.linux-armv7l/egg/pymodbus/transaction.py", line 692, in _process
    result = self.decoder.decode(data)
  File "build/bdist.linux-armv7l/egg/pymodbus/factory.py", line 223, in decode
    return self._helper(message)
  File "build/bdist.linux-armv7l/egg/pymodbus/factory.py", line 237, in _helper
    function_code = byte2int(data[0])
IndexError: string index out of range

[29/Jan/2018 11:58:28] CRITICAL [api.reader:69] Exiting because a reader daemon is dead!

@dhoomakethu
Copy link
Contributor

@ccatterina I am a bit confused now, Are you using the ModbusSerialClient provided by the pymodbus library or are you creating your own ? The logs shows you are not using the ModbusSerialClient from sync.py. The logs would then be more descriptive like this

[DEBUG    2018-01-29 04:06:59,102  pymodbus.client.sync 443] Changing state to IDLE - Last Frame End - 1517227619.06, Current Time stamp - 1517227619.1
[DEBUG    2018-01-29 04:06:59,104  pymodbus.client.sync 459] Transaction state 'IDLE', intiating a new transaction
[DEBUG    2018-01-29 04:06:59,107  pymodbus.client.sync 481] Changing transaction state from 'SENDING' to 'WAITING FOR REPLY'
[DEBUG    2018-01-29 04:06:59,166  pymodbus.client.sync 499] Changing transaction state from 'WAITING FOR REPLY' to 'PROCESSING REPLY'
[DEBUG    2018-01-29 04:06:59,172  pymodbus.transaction 202] RECV: 0x1 0x3 0x4 0x0 0x0 0x0 0x0 0xfa 0x33
[DEBUG    2018-01-29 04:06:59,174  pymodbus.transaction 732] Getting Frame - 0x3 0x4 0x0 0x0 0x0 0x0
[DEBUG    2018-01-29 04:06:59,177  pymodbus.factory 238] Factory Response[3]
[DEBUG    2018-01-29 04:06:59,180  pymodbus.transaction 672] Frame advanced, resetting header!!
[DEBUG    2018-01-29 04:06:59,182  pymodbus.transaction 395] Adding transaction 0
[DEBUG    2018-01-29 04:06:59,185  pymodbus.transaction 405] Getting transaction 12223
[DEBUG    2018-01-29 04:06:59,187  pymodbus.transaction 175] Changing transaction state from 'PROCESSING REPLY' to 'TRANSCATION_COMPLETE'

With this branch most of the devices we have which were bailing out with similar errors are working just fine. I could not get the modbus spec for the device you have mentioned. In any case if it is a modbus serial device you are trying , try updating this stand-alone-script with relevant details and share the logs here.

@ccatterina
Copy link
Contributor

Oh Sorry, i'm using ModbusTcpClient with Rtu framer, i thought i had already specificied It.

@dhoomakethu
Copy link
Contributor

dhoomakethu commented Jan 29, 2018

@ccatterina Thanks for the clarification, will run the tests with your setup and will get back to you. I am sure the use case you are trying is not covered . Sorry for the trouble.

ccatterina pushed a commit to ccatterina/pymodbus that referenced this pull request Apr 17, 2018
If an incomplete response is received strange things happened
(e.g. receiving 0xFF raise an IndexError, receiving 0x011012
raise a struct.error).
Now if an incomplete response is received an error is logged.

Related to discussion in pymodbus-dev#188 , Fix pymodbus-dev#211
ccatterina pushed a commit to ccatterina/pymodbus that referenced this pull request Apr 18, 2018
If an incomplete response is received strange things happened
(e.g. receiving 0xFF raise an IndexError, receiving 0x011012
raise a struct.error).
Now if an incomplete response is received an error is logged.

Related to discussion in pymodbus-dev#188 , Fix pymodbus-dev#211
dhoomakethu added a commit that referenced this pull request Apr 26, 2018
*  Modbus sync client timing enhancements #221
 Fix TCP server #256, #260

* Fix #221 timing enhancements, #188 workarounds

* 1. #284 Async servers - Option to start reactor outside Start<server>Server function
2. #283 Fix BinaryPayloadDecoder/Builder issues when using with pymodbus server
3. #278 Fix issue with sync/async servers failing to handle requests with transaction id > 255
4. #221 Move timing and transcational logic to framers for sync clients
5. #221 More debug logs for sync clients
6. Misc updates with examples and minor enhancements

* 1. #277 MEI message reception issue with UDP client
2. Fix unit tests
3. Update changelog

* Patch 1 (#292)

* Fix #289 and other misc enhancements

* Replace nosetest with pytest

* Update Changelog

* serial sync client wait till timeout/some data is available in read buffer + update changelog

* serial sync client read updates when timeout is None and Zero

* fix sync client unit test and example
@dhoomakethu
Copy link
Contributor

@ccatterina I hope this PR is no longer valid and shall be taken care as part of 1.5.0. Please feel free to open with an updated PR if you still feel this is an issue.

@github-actions github-actions bot locked as resolved and limited conversation to collaborators Apr 21, 2023
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.