brendan-w / python-OBD

OBD-II serial module for reading engine data
GNU General Public License v2.0
1.02k stars 360 forks source link

Some commands seem to be decoded incorrectly (get "Message was shorter than expected.") #132

Open graus opened 5 years ago

graus commented 5 years ago

I have been trying to run this python-obd on my Raspberry pi, but am facing some issues with some of the return values. I connect as follows;

conn = obd.OBD(portstr="/dev/rfcomm0", baudrate=10400, fast=False)

However, I noticed except for a few commands (RPM, FUEL_STATUS, O2_B1S1, O2_B1S2) when I write the values (command.value) most of the results never change, and stay at their default/0 value (e.g., COOLANT_TEMP=-40 degC, SPEED=0 kph, etc.). While the raw return values do change in the logs.

Looking into the logs, I see I always get 'Messages shorter than expected.', e.g.:

Jan 13 16:42:30 pihatsu rc.local[400]: [obd.obd] Sending command: b'0105': Engine Coolant Temperature
Jan 13 16:42:30 pihatsu rc.local[400]: [obd.elm327] write: b'0105\r\n'
Jan 13 16:42:31 pihatsu rc.local[400]: [obd.elm327] read: b'83F110410586\r\r>'
Jan 13 16:42:31 pihatsu rc.local[400]: [obd.OBDCommand] Message was shorter than expected. Padded message: bytearray(b'A\x05\x00')
[...]
Jan 13 16:44:17 pihatsu rc.local[400]: [obd.obd] Sending command: b'0105': Engine Coolant Temperature
Jan 13 16:44:17 pihatsu rc.local[400]: [obd.elm327] write: b'0105\r\n'
Jan 13 16:44:17 pihatsu rc.local[400]: [obd.elm327] read: b'83F11041058A\r\r>'
Jan 13 16:44:17 pihatsu rc.local[400]: [obd.OBDCommand] Message was shorter than expected. Padded message: bytearray(b'A\x05\x00')

I tried the above using the pypi version of python-OBD, which sent commands with trailing newlines to my OBD2 reader, which I hoped caused the issue.

But after cloning + installing the current git master (which I inferred from this line, is different), I still get the same:

Jan 14 16:51:21 pihatsu rc.local[274]: [obd.obd] Sending command: b'0100': Supported PIDs [01-20]
Jan 14 16:51:21 pihatsu rc.local[274]: [obd.elm327] write: b'0100\r'
Jan 14 16:51:21 pihatsu rc.local[274]: [obd.elm327] read: b'86F1104100BE3EB811\r\r>'
Jan 14 16:51:21 pihatsu rc.local[274]: [obd.OBDCommand] Message was shorter than expected. Padded message: bytearray(b'A\x00\xbe>\xb8\x00')
[...]
Jan 14 16:51:22 pihatsu rc.local[274]: [obd.obd] Sending command: b'0105': Engine Coolant Temperature
Jan 14 16:51:22 pihatsu rc.local[274]: [obd.elm327] write: b'0105\r'
Jan 14 16:51:22 pihatsu rc.local[274]: [obd.elm327] read: b'83F11041053F\r\r>'
Jan 14 16:51:22 pihatsu rc.local[274]: [obd.OBDCommand] Message was shorter than expected. Padded message: bytearray(b'A\x05\x00')
[...]
Jan 14 16:51:24 pihatsu rc.local[274]: [obd.obd] Sending command: b'010C': Engine RPM
Jan 14 16:51:24 pihatsu rc.local[274]: [obd.elm327] write: b'010C\r'
Jan 14 16:51:24 pihatsu rc.local[274]: [obd.elm327] read: b'84F110410C1685\r\r>'
Jan 14 16:51:24 pihatsu rc.local[274]: [obd.OBDCommand] Message was shorter than expected. Padded message: bytearray(b'A\x0c\x16\x00')
Jan 14 16:51:24 pihatsu rc.local[274]: [obd.obd] Sending command: b'010D': Vehicle Speed
Jan 14 16:51:24 pihatsu rc.local[274]: [obd.elm327] write: b'010D\r'
Jan 14 16:51:25 pihatsu rc.local[274]: [obd.elm327] read: b'83F110410D00\r\r>'
Jan 14 16:51:25 pihatsu rc.local[274]: [obd.OBDCommand] Message was shorter than expected. Padded message: bytearray(b'A\r\x00')
[...]
Jan 14 16:51:25 pihatsu rc.local[274]: [obd.obd] Sending command: b'010F': Intake Air Temp
Jan 14 16:51:25 pihatsu rc.local[274]: [obd.elm327] write: b'010F\r'
Jan 14 16:51:25 pihatsu rc.local[274]: [obd.elm327] read: b'83F110410F2E\r\r>'
Jan 14 16:51:25 pihatsu rc.local[274]: [obd.OBDCommand] Message was shorter than expected. Padded message: bytearray(b'A\x0f\x00')

It seems to me what is returned to be OK; e.g., command: b'0100': Supported PIDs [01-20] yields 4 bytes (86F11041 00 BE 3E B8 11 (?)) command: b'010C': Engine RPM yields: 84F11041 + 0C + 16 + 85 (?), and inputting them in this online OBD2 message converter does seem to yield correct numbers (e.g., an engine coolant temperature of 23).

Any clue what might cause this, or why I'm getting these too-short responses?

alistair23 commented 5 years ago

Hey, sorry for the slow response. I can't reproduce the error so it's hard to debug. Do you want to try and see what causes the "Message was shorter than expected" message to occur?

alistair23 commented 5 years ago

A quick look shows that the padding give you bad values. Do you mind adding some more prints yourself and see what else you can find?

graus commented 5 years ago

Yeah, I tried to force query all commands, and each command yields the same message/padding issue;

Jan 14 16:51:13 pihatsu rc.local[274]: [obd.obd] ======================= python-OBD (v0.7.0) =======================
Jan 14 16:51:13 pihatsu rc.local[274]: [obd.obd] Explicit port defined
Jan 14 16:51:13 pihatsu rc.local[274]: [obd.elm327] Initializing ELM327: PORT=/dev/rfcomm0 BAUD=10400 PROTOCOL=auto
Jan 14 16:51:13 pihatsu rc.local[274]: [obd.elm327] write: b'ATZ\r'
Jan 14 16:51:15 pihatsu rc.local[274]: [obd.elm327] wait: 1 seconds
Jan 14 16:51:16 pihatsu rc.local[274]: [obd.elm327] read: b'ELM327 v2.1\r>'
Jan 14 16:51:16 pihatsu rc.local[274]: [obd.elm327] write: b'ATE0\r'
Jan 14 16:51:16 pihatsu rc.local[274]: [obd.elm327] read: b'OK\r>'
Jan 14 16:51:16 pihatsu rc.local[274]: [obd.elm327] write: b'ATH1\r'
Jan 14 16:51:16 pihatsu rc.local[274]: [obd.elm327] read: b'OK\r>'
Jan 14 16:51:16 pihatsu rc.local[274]: [obd.elm327] write: b'ATL0\r'
Jan 14 16:51:16 pihatsu rc.local[274]: [obd.elm327] read: b'OK\r>'
Jan 14 16:51:16 pihatsu rc.local[274]: [obd.elm327] write: b'AT RV\r'
Jan 14 16:51:16 pihatsu rc.local[274]: [obd.elm327] read: b'14.2V\r>'
Jan 14 16:51:16 pihatsu rc.local[274]: [obd.elm327] write: b'ATSP0\r'
Jan 14 16:51:16 pihatsu rc.local[274]: [obd.elm327] read: b'OK\r>'
Jan 14 16:51:16 pihatsu rc.local[274]: [obd.elm327] write: b'0100\r'
Jan 14 16:51:20 pihatsu rc.local[274]: [obd.elm327] read: b'SEARCHING...\r86F1104100BE3EB811\r\r>'
Jan 14 16:51:20 pihatsu rc.local[274]: [obd.elm327] write: b'ATDPN\r'
Jan 14 16:51:20 pihatsu rc.local[274]: [obd.elm327] read: b'A4\r>'
Jan 14 16:51:20 pihatsu rc.local[274]: [obd.protocols.protocol] map ECU 16 --> ENGINE
Jan 14 16:51:20 pihatsu rc.local[274]: [obd.elm327] Connected Successfully: PORT=/dev/rfcomm0 BAUD=10400 PROTOCOL=4
Jan 14 16:51:21 pihatsu rc.local[274]: [obd.obd] querying for supported commands
Jan 14 16:51:21 pihatsu rc.local[274]: [obd.obd] Sending command: b'0100': Supported PIDs [01-20]
Jan 14 16:51:21 pihatsu rc.local[274]: [obd.elm327] write: b'0100\r'
Jan 14 16:51:21 pihatsu rc.local[274]: [obd.elm327] read: b'86F1104100BE3EB811\r\r>'
Jan 14 16:51:21 pihatsu rc.local[274]: [obd.OBDCommand] Message was shorter than expected. Padded message: bytearray(b'A\x00\xbe>\xb8\x00')
Jan 14 16:51:21 pihatsu rc.local[274]: [obd.obd] finished querying with 37 commands supported
Jan 14 16:51:21 pihatsu rc.local[274]: [obd.obd] ===================================================================
Jan 14 16:51:21 pihatsu rc.local[274]: [obd.obd] Sending command: b'0100': Supported PIDs [01-20]
Jan 14 16:51:21 pihatsu rc.local[274]: [obd.elm327] write: b'0100\r'
Jan 14 16:51:21 pihatsu rc.local[274]: [obd.elm327] read: b'86F1104100BE3EB811\r\r>'
Jan 14 16:51:21 pihatsu rc.local[274]: [obd.OBDCommand] Message was shorter than expected. Padded message: bytearray(b'A\x00\xbe>\xb8\x00')
Jan 14 16:51:21 pihatsu rc.local[274]: [obd.obd] Sending command: b'0101': Status since DTCs cleared
Jan 14 16:51:21 pihatsu rc.local[274]: [obd.elm327] write: b'0101\r'
Jan 14 16:51:21 pihatsu rc.local[274]: [obd.elm327] read: b'86F110410100676501\r\r>'
Jan 14 16:51:21 pihatsu rc.local[274]: [obd.OBDCommand] Message was shorter than expected. Padded message: bytearray(b'A\x01\x00ge\x00')
Jan 14 16:51:21 pihatsu rc.local[274]: [obd.obd] Sending command: b'0102': DTC that triggered the freeze frame
Jan 14 16:51:21 pihatsu rc.local[274]: [obd.elm327] write: b'0102\r'
Jan 14 16:51:22 pihatsu rc.local[274]: [obd.elm327] read: b'83F1107F0112\r\r>'
Jan 14 16:51:22 pihatsu rc.local[274]: [obd.OBDCommand] Message was shorter than expected. Padded message: bytearray(b'\x7f\x01\x00\x00')
Jan 14 16:51:22 pihatsu rc.local[274]: [obd.obd] Sending command: b'0103': Fuel System Status
Jan 14 16:51:22 pihatsu rc.local[274]: [obd.elm327] write: b'0103\r'
Jan 14 16:51:22 pihatsu rc.local[274]: [obd.elm327] read: b'84F11041030100\r\r>'
Jan 14 16:51:22 pihatsu rc.local[274]: [obd.OBDCommand] Message was shorter than expected. Padded message: bytearray(b'A\x03\x01\x00')
[...]
Jan 14 16:51:46 pihatsu rc.local[274]: [obd.obd] Sending command: b'015D': Fuel injection timing
Jan 14 16:51:46 pihatsu rc.local[274]: [obd.elm327] write: b'015D\r'
Jan 14 16:51:46 pihatsu rc.local[274]: [obd.elm327] read: b'83F1107F0112\r\r>'
Jan 14 16:51:46 pihatsu rc.local[274]: [obd.OBDCommand] Message was shorter than expected. Padded message: bytearray(b'\x7f\x01\x00\x00')
Jan 14 16:51:46 pihatsu rc.local[274]: [obd.obd] Sending command: b'015E': Engine fuel rate
Jan 14 16:51:46 pihatsu rc.local[274]: [obd.elm327] write: b'015E\r'
Jan 14 16:51:46 pihatsu rc.local[274]: [obd.elm327] read: b'83F1107F0112\r\r>'
Jan 14 16:51:46 pihatsu rc.local[274]: [obd.OBDCommand] Message was shorter than expected. Padded message: bytearray(b'\x7f\x01\x00\x00')
Jan 14 16:51:46 pihatsu rc.local[274]: [obd.obd] Sending command: b'015F': Designed emission requirements
Jan 14 16:51:46 pihatsu rc.local[274]: [obd.elm327] write: b'015F\r'
Jan 14 16:51:46 pihatsu rc.local[274]: [obd.elm327] read: b'83F1107F0112\r\r>'
Jan 14 16:51:46 pihatsu rc.local[274]: [obd.OBDCommand] Message was shorter than expected. Padded message: bytearray(b'\x7f\x01\x00')

I did try interfacing directly with the rfcomm0 port through screen, and do get responses there. Maybe per reference, I am following much of this guide.

Would you have any suggestion what to try specifically?

alistair23 commented 5 years ago

I would add prints everywhere you can in the path to the padding message and see if anything looks weird. If you then share the changes you made I can compare with my working setup. From your log above it looks like the padding is clearing the data

graus commented 5 years ago

OK, I've added some prints to the OBDCommand.py

Below are some of the responses/messages I receive. Not sure if this is as expected?

[obd.elm327] Connected Successfully: PORT=/dev/rfcomm0 BAUD=38400 PROTOCOL=4
[obd.obd] Sending command: b'0103': Fuel System Status
[obd.elm327] write: b'0103\r'
[obd.elm327] read: b'84F11041030200\r\r>'
[obd.OBDCommand] MessageData: bytearray(b'A\x03\x02')
[obd.OBDCommand] MessageDataLen: 3
[obd.OBDCommand] self.bytes: 4
[obd.OBDCommand] Message was shorter than expected. Padded message: bytearray(b'A\x03\x02\x00')
[obd.decoders] Invalid response for fuel status (multiple/no bits set)
[obd.obd] Sending command: b'0104': Calculated Engine Load
[obd.elm327] write: b'0104\r'
[obd.elm327] read: b'83F11041040C\r\r>'
[obd.OBDCommand] MessageData: bytearray(b'A\x04')
[obd.OBDCommand] MessageDataLen: 2
[obd.OBDCommand] self.bytes: 3
[obd.OBDCommand] Message was shorter than expected. Padded message: bytearray(b'A\x04\x00')
[obd.obd] Sending command: b'0105': Engine Coolant Temperature
[obd.elm327] write: b'0105\r'
[obd.elm327] read: b'83F110410551\r\r>'
[obd.OBDCommand] MessageData: bytearray(b'A\x05')
[obd.OBDCommand] MessageDataLen: 2
[obd.OBDCommand] self.bytes: 3
[obd.OBDCommand] Message was shorter than expected. Padded message: bytearray(b'A\x05\x00')
[obd.obd] Sending command: b'010C': Engine RPM
[obd.elm327] write: b'010C\r'
[obd.elm327] read: b'84F110410C1377\r\r>'
[obd.OBDCommand] MessageData: bytearray(b'A\x0c\x13')
[obd.OBDCommand] MessageDataLen: 3
[obd.OBDCommand] self.bytes: 4
[obd.OBDCommand] Message was shorter than expected. Padded message: bytearray(b'A\x0c\x13\x00')
graus commented 5 years ago

OK! I managed to fix it, I figured I'd try to not prune the last (checksum?) byte, i.e., I turned obd/protocols/protocol_legacy.py#L76 into:

frame.data = raw_bytes[3:]

And now I have data coming in...

FUEL_STATUS ENGINE_LOAD COOLANT_TEMP SHORT_FUEL_TRIM_1 LONG_FUEL_TRIM_1 INTAKE_PRESSURE RPM SPEED TIMING_ADVANCE INTAKE_TEMP THROTTLE_POS O2_SENSORS O2_B1S1 O2_B1S2
('Closed loop, using oxygen sensor feedback to... 9.803921568627452 percent 64 degC 0.0 percent 25.78125 percent 42 kilopascal 1333.75 revolutions_per_minute 4 kph 2.0 degree 23 degC 2.3529411764705883 percent ((), (False, False, False, False), (False, Fal... 0.055 volt 0.79 volt
('Closed loop, using oxygen sensor feedback to... 10.196078431372548 percent 64 degC 2.34375 percent 34.375 percent 47 kilopascal 1672.75 revolutions_per_minute 12 kph 16.5 degree 23 degC 8.235294117647058 percent ((), (False, False, False, False), (False, Fal... 0.655 volt 0.785 volt
('Closed loop, using oxygen sensor feedback to... 4.705882352941177 percent 64 degC 2.34375 percent 25.78125 percent 23 kilopascal 1458.5 revolutions_per_minute 11 kph 13.0 degree 23 degC 0.39215686274509803 percent ((), (False, False, False, False), (False, Fal... 0.085 volt 0.795 volt

Still no clue why, but as far as I'm concerned this can be closed --- if there's anything I can help with (if you'd like to explore and/or want logs), let me know!

alistair23 commented 5 years ago

Great! I'm glad it's working.

It sounds like a bug then, do you mind submitting a pull request for the fix?

Are you using an official ELM327 device?

graus commented 5 years ago

I wouldn't mind submitting a PR, but I'm not sure whether it is a general thing or something specific with my setup/hardware: I've seen multiple sources mention the last byte of the response should be omitted. Seeing I couldn't find any prior issues that are about the same thing, I think it's unlikely that everyone that needs the legacy_protocol has the same issue...?

alistair23 commented 5 years ago

I'm not sure, but I think it makes sense to have that discussion in the PR. Even if it doesn't get merged it will be helpful for others to find in the future. I haven't looked into if it's a correct fix or not, but I think it's at least worth discussing.

Ircama commented 5 years ago

Are you sure that the output produced after your modification is correct?

From a first check, it looks like your adapter:

Here is a comparison of a valid ISO 15765 ‘0100’ answer with yours:

  7E8 06 41 00 BE 3F A8 13 (valid: 7E8 = CAN ID, 06 = length)
86 F1 10 41 00 BE 3E B8 11 (yours; 6 = length)

This is with a valid ISO 15765 ‘010C’ answer and yours:

7E8 04 41 0C 00 00 (valid: 7E8 = CAN ID, 04 = length)
84F110 41 0C 16 85 (yours; 4 = length)

I think that python-OBD is not currently able to manage such headers. Can you share a documentation of the protocol specification of your ELM327 adapter?


I made some quick investigations and yours could be the ISO 14230-4 KWP protocol (I was referring to ISO 15765 / CAN as comparison). Is this protocol supported here? I do not know, I am afraid not.

graus commented 5 years ago

I have no clue, where could I find documentation? The auto-detected protocol is ISO_14230_4_5baud, and w.r.t.: "Are you sure that the output produced after your modification is correct?"

Pretty sure, I think the incoming data looks pretty plausible (snippet of small drive around the block);

screen shot 2019-01-23 at 10 52 25 am
Ircama commented 5 years ago

I checked all these legacy protocols (at least for single frame cases) and actually they include a three-byte header (even if the one of ISO_14230_4 differs from SAE_J1850 and ISO_9141_2); they should also include a trailing checksum. So the code might support all of them (anyway, a good thing for ISO 14230-4 could be to also check the data size). By the way, you are right that your adapter does not generate a checksum.