Odd error reading RPM from kona electric

Trying to read a RPM PID I see in the minion logs -

2019-03-07 17:57:14,363 [messaging        :222 ][ERROR   ][863] Recurring exception (2 times) in worker thread 'readout_30sec' while running workflow for message: {'filter': 'alternating_readout', 'handler': 'query', 'returner': 'cloud', 'args': ['Motor_RPM_2'], 'kwargs': {'force': True, 'pid': 101, 'header': '7E4', 'mode': 220, 'formula': 'twos_comp(bytes_to_int(message.data[58:59])*256+bytes_to_int(message.data[59:60]),16)', 'protocol': 'auto'}}
Traceback (most recent call last):
  File "/var/cache/salt/minion/extmods/utils/messaging.py", line 188, in do_work
    self._call_hook_for(message, "workflow", message)
  File "/var/cache/salt/minion/extmods/utils/messaging.py", line 395, in _call_hook_for
    return True, func(*args, **kwargs)
  File "/var/cache/salt/minion/extmods/utils/messaging.py", line 326, in extended_workflow
    self._call_hook_for(message, "returner", message, result)
  File "/var/cache/salt/minion/extmods/utils/messaging.py", line 395, in _call_hook_for
    return True, func(*args, **kwargs)
  File "/var/cache/salt/minion/extmods/utils/messaging.py", line 561, in returner_wrapper
    return returner_func(result, *args, **kwargs)
  File "/var/cache/salt/minion/extmods/returners/cloud_returner.py", line 189, in returner_data
    cloud_cache.enqueue(r)
  File "/var/cache/salt/minion/extmods/utils/cloud_cache.py", line 79, in enqueue
    self.client.lpush(self.PENDING_QUEUE, json.dumps(data, separators=(",", ":")))
  File "/usr/local/lib/python2.7/dist-packages/redis/client.py", line 1333, in lpush
    return self.execute_command('LPUSH', name, *values)
  File "/usr/local/lib/python2.7/dist-packages/redis/client.py", line 673, in execute_command
    connection.send_command(*args)
  File "/usr/local/lib/python2.7/dist-packages/redis/connection.py", line 610, in send_command
    self.send_packed_command(self.pack_command(*args))
  File "/usr/local/lib/python2.7/dist-packages/redis/connection.py", line 585, in send_packed_command
    self.connect()
  File "/usr/local/lib/python2.7/dist-packages/redis/connection.py", line 489, in connect
    raise ConnectionError(self._error_message(e))

Now raw data is -

  7EC103E620101FFF7E7
  7EC21FFBC19AA465003
  7EC22FFEA0FD10B0A0A
  7EC230A0A0A00000ACE
  7EC244BCE4600009300
  7EC2500635E00006022
  7EC26000025B7000023
  7EC2716001227EB0901
  7EC28940000000003E8

Debuging I notice the following extracts a byte correctly -

$  obd.query Motor_RPM_1 mode=220 pid=101 header='7E4' bytes=62 formula='bytes_to_int(message.data[55:56])' force=true
_type: motor_rpm_1
_stamp: '2019-03-07T20:05:04.742986'
value: 148

( 148 = 0x94 which we see on the last row )

But trying to get the next byte fails -

$  obd.query Motor_RPM_1 mode=220 pid=101 header='7E4' bytes=62 formula='bytes_to_int(message.data[56:57])' force=true
_type: motor_rpm_1
_stamp: '2019-03-07T20:07:02.456788'
value: |-
  7EC103E620101FFF7E7
  7EC21FFBC197D465003
  7EC22FFE80FD30B0A0A
  7EC230A0A0A00000ACE
  7EC2447CE4600009300
  7EC2500636000006022
  7EC26000025B8000023
  7EC2716001229110901
  7EC28940000000003E8

Instead of a single byte returned, the whole message is.

I’m wondering if there is a limit to the size of a message ?

I did try increasing bytes but it didn’t seem to make much difference.

1 Like

Oh, this appears to correlate to minion log -

2019-03-07 20:01:31,878 [obd.OBDCommand :118 ][WARNING ][820] Message was shorter than expected - padded message: bytearray(b'b\x01\x01\xff\xf7\xe7\xff\xbc\x19\xaaFP\x03\xff\xe8\x0f\xd1\x0b\n\n\n\n\n\x00\x00\n\xceK\xceF\x00\x00\x93\x00\x00c]\x00\x00"\x00\x00%\xb7\x00\x00#\x16\x00\x12’\xc6\t\x01\x94\x00\x00\x00\x00\x03\xe8\x00\x00’)`

1 Like

Here is another -

$ obd.query Charge_Port mode=220 pid=101 header='7E4' bytes=64 formula='bytes_to_int(message.data[12:13])' unit=% baudrate=500000 protocol=6 verify=false force=true
value: |-
  7EC103E620101FFF7E7
  7EC21FFAD2559465000
  7EC2200000F770B0A0A
  7EC230A0A0A00000CCA
  7EC2430C94600007A00
  7EC2500640600006152
  7EC26000025F9000023
  7EC278C00124E5D0900
  7EC28030000000003E8
_stamp: '2019-03-09T13:29:09.420168'
_type: charge_port

unit: '%'

According to the formula, one byte should be returned but we see the whole message.

The same query run by the logger I see the correct result in one case -

2019-03-09 13:21:54,252 [salt.loaded.ext.engines.obd_manager:65  ][DEBUG   ][1581] Querying: Charge_Port
2019-03-09 13:21:54,258 [obd.obd          :267 ][DEBUG   ][1581] Querying command: 220101: None
2019-03-09 13:21:54,263 [obd.interfaces.elm327:827 ][DEBUG   ][1581] Write: 'ATSH7E4\r'
2019-03-09 13:21:54,266 [salt.loaded.ext.engines.obd_manager:591 ][DEBUG   ][1581] Listener got RPM result: {'_type': 'rpm'}
2019-03-09 13:21:54,275 [obd.interfaces.elm327:883 ][DEBUG   ][1581] Read: b'OK\r\r>'
2019-03-09 13:21:54,281 [obd.interfaces.elm327:509 ][DEBUG   ][1581] Changed header from '7DF' to '7E4'
2019-03-09 13:21:54,286 [obd.interfaces.elm327:827 ][DEBUG   ][1581] Write: '220101\r'
2019-03-09 13:21:54,414 [obd.interfaces.elm327:883 ][DEBUG   ][1581] Read: b'7EC 10 3E 62 01 01 FF F7 E7 \r7EC 21 FF AD 25 59 46 50 03 \r7EC 22 FF 55 0F 8F 0A 0A 0A \r7EC 23 0A 0A 0A 00 00 0C CB \r7EC 24 47 CB 38 00 00 94 00 \r7EC 25 00 64 05 00 00 61 52 \r7EC 26 00 00 25 F9 00 00 23 \r7EC 27 8C 00 12 4C C4 09 01 \r7EC 28 8E 00 00 00 00 03 E8 \r\r>'
2019-03-09 13:21:54,429 [salt.loaded.ext.engines.obd_manager:104 ][DEBUG   ][1581] Got query result: 3

but another case -

2019-03-09 13:25:04,635 [salt.loaded.ext.engines.obd_manager:65  ][DEBUG   ][1581] Querying: Charge_Port
2019-03-09 13:25:04,641 [obd.obd          :267 ][DEBUG   ][1581] Querying command: 220101: None
2019-03-09 13:25:04,646 [salt.loaded.ext.engines.obd_manager:614 ][DEBUG   ][1581] Listener got battery result: {'_type': 'bat', 'voltage': 12.4, 'state': 'discharging', 'level': 80}
2019-03-09 13:25:04,651 [messaging        :668 ][DEBUG   ][1581] Skipping duplicate event with tag 'vehicle/battery/discharging': {'level': 80}
2019-03-09 13:25:04,655 [obd.interfaces.elm327:827 ][DEBUG   ][1581] Write: 'ATSH7E4\r'
2019-03-09 13:25:04,662 [obd.interfaces.elm327:883 ][DEBUG   ][1581] Read: b'OK\r\r>'
2019-03-09 13:25:04,669 [obd.interfaces.elm327:509 ][DEBUG   ][1581] Changed header from '7DF' to '7E4'
2019-03-09 13:25:04,673 [obd.interfaces.elm327:827 ][DEBUG   ][1581] Write: '220101\r'
2019-03-09 13:25:04,801 [obd.interfaces.elm327:883 ][DEBUG   ][1581] Read: b'7EC 10 3E 62 01 01 FF F7 E7 \r7EC 21 FF AD 25 59 46 50 00 \r7EC 22 00 00 0F 79 0B 0A 0A \r7EC 23 0A 0A 0A 00 00 0C CA \r7EC 24 30 C9 46 00 00 7C 00 \r7EC 25 00 64 06 00 00 61 52 \r7EC 26 00 00 25 F9 00 00 23 \r7EC 27 8C 00 12 4D 68 09 00 \r7EC 28 03 00 00 00 00 03 E8 \r\r>'
2019-03-09 13:25:04,815 [salt.loaded.ext.engines.obd_manager:104 ][DEBUG   ][1581] Got query result: 7EC103E620101FFF7E7

Hi @plord,

These issues should have been resolved with the latest bug release today.

Let us know if the keep appearing.

best
Peter

1 Like

Many thanks … lots of testing over the next few days !

I’ve still seeing this effect. Eg -

 $ obd.query Real_Speed mode=21 pid=1 header=7E2 bytes=27 formula='bytes_to_int(message.data[13:14])' unit=mph baudrate=500000 protocol=6 verify=false force=true
value: |-
  7EA10186101FFF80000
  7EA21092110FF050703
  7EA22000000009C7740
  7EA2307202005000000
_stamp: '2019-03-13T18:48:12.100430'
_type: real_speed
unit: mph

Hi Peter

I think we have found the issue in our end.
We had some logic that checked the value after parsing it, to see if it was ‘anything’, and when speaking ‘python’ 0 doesn’t count as anything. If the value was anything, it was returned, if not the original unparsed value was returned.

And since your query is called read_speed, and that i’m guessing that you aren’t driving while executing the command, I think that check might be the cause of the issue.
Does that sound plausible? Could the value have been zero when the issue occurred?

We have fixed it in the core repository, but it is not yet deployed.

Best regards
/Malte

Yes - (very) plausible. I noticed the same with rpm ( when the car was sat on my drive ! ).

Many thanks,

Pete

1 Like