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

[graus]

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]

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]

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]

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]

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]

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?

• I don't know what the As are?
• The message seems to omit the last byte from the response, e.g., 83F11041 + 040C yields \x04 and 83F11041 + 0551 yields \x05?

[obd.elm327] Connected Successfully: PORT=/dev/rfcomm0 BAUD=38400 PROTOCOL=4

• Protocol 4 means I should be looking at LegacyProtocol?

[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]

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]

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]

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]

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]

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

From a first check, it looks like your adapter:

• does not produce spaced answer, but in principle this is not an issue for python-OBD. Output can be spaced through AT S1. Anyway the specification says that by default spaces are on (S1) and space characters are inserted in every response; so, your adapter has a different default after ATZ.
• adds its own header and CAN ID ~~instead of a classic one like 7E8; I do not know whether this different header is valid~~ (check for instance 83F110, 86F110, 84F110)
• ~~might not add a length byte in its classic position, after the CAN ID (ECU)~~. The length appears in the first byte of the answer (3, 6, 4 in the above examples).

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]

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);

[Ircama]

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.