Equipment-and-Tool-Institute / j1939-84

J1939-84 implementation for etools.org
MIT License
7 stars 6 forks source link

Tool Doesn't Acknowledge All DM19 Responses from Distributed System #1168

Closed naroner closed 1 month ago

naroner commented 1 year ago

V3.1.3 doesn't appear to acknowledge DM19 responses from multiple ECUs during a global request. The tool only appears to see the last response on the bus

Start Test 1.7 - DM19: Calibration information 13:26:33.8794 Global DM19 Request 13:26:33.8819 18EAFFF9 [3] 00 D3 00 (TX) 13:26:34.4849 1CD3FF3D [80] D2 98 DA DD 33 41 71 31 30 32 4E 32 4D 32 31 30 30 30 33 31 72 14 4D A8 4E 4F 78 2D 53 57 37 30 30 38 20 41 54 49 31 00 72 14 4D A8 4E 4F 78 2D 53 57 37 30 30 38 20 41 54 4F 31 00 3C D4 F9 EE 50 4D 53 2A 31 32 2A 33 33 30 2A 41 31 30 30 00 DM19 from Exhaust Emission Controller (61): [ CAL ID of 3Aq102N2M2100031 and CVN of 0xDDDA98D2 CAL ID of NOx-SW7008 ATI1 and CVN of 0xA84D1472 CAL ID of NOx-SW7008 ATO1 and CVN of 0xA84D1472 CAL ID of PMS12330*A100 and CVN of 0xEEF9D43C ]

FAIL: 6.1.7.2.a - Total number of reported CAL IDs is < user entered value for number of emission or diagnostic critical control units WARN: 6.1.7.3.b - Exhaust Emission Controller (61) provided more than one CAL ID and CVN pair in a single DM19 message FAIL: 6.1.7.2.b.ii - Exhaust Emission Controller (61) CAL ID not formatted correctly (contains non-printable ASCII) FAIL: 6.1.7.2.b.ii - Exhaust Emission Controller (61) CAL ID not formatted correctly (contains non-printable ASCII) FAIL: 6.1.7.2.b.ii - Exhaust Emission Controller (61) CAL ID not formatted correctly (contains non-printable ASCII) 13:26:34.4934 Destination Specific DM19 Request to Engine #1 (0) 13:26:34.4959 18EA00F9 [3] 00 D3 00 (TX) 13:26:34.5519 1CD3F900 [20] 3C B4 8D A6 35 54 32 31 34 32 30 30 41 30 30 30 30 30 30 30 DM19 from Engine #1 (0): CAL ID of 5T214200A0000000 and CVN of 0xA68DB43C 13:26:34.5534 Destination Specific DM19 Request to Engine #2 (1) 13:26:34.5569 18EA01F9 [3] 00 D3 00 (TX) 13:26:34.6264 1CD3F901 [20] 5B 68 CA 16 34 4A 32 31 33 32 53 30 30 32 33 31 35 54 43 4F DM19 from Engine #2 (1): CAL ID of 4J2132S002315TCO and CVN of 0x16CA685B 13:26:34.6284 Destination Specific DM19 Request to Exhaust Emission Controller (61) 13:26:34.6304 18EA3DF9 [3] 00 D3 00 (TX) 13:26:34.7534 1CD3F93D [80] D2 98 DA DD 33 41 71 31 30 32 4E 32 4D 32 31 30 30 30 33 31 72 14 4D A8 4E 4F 78 2D 53 57 37 30 30 38 20 41 54 49 31 00 72 14 4D A8 4E 4F 78 2D 53 57 37 30 30 38 20 41 54 4F 31 00 3C D4 F9 EE 50 4D 53 2A 31 32 2A 33 33 30 2A 41 31 30 30 00 DM19 from Exhaust Emission Controller (61): [ CAL ID of 3Aq102N2M2100031 and CVN of 0xDDDA98D2 CAL ID of NOx-SW7008 ATI1 and CVN of 0xA84D1472 CAL ID of NOx-SW7008 ATO1 and CVN of 0xA84D1472 CAL ID of PMS12330*A100 and CVN of 0xEEF9D43C ] FAIL: 6.1.7.5.c - OBD ECU Engine #1 (0) did not provide a response to Global query and did not provide a NACK for the DS query FAIL: 6.1.7.5.c - OBD ECU Engine #2 (1) did not provide a response to Global query and did not provide a NACK for the DS query

FAIL: 6.1.7.2.a - Total number of reported CAL IDs is < user entered value for number of emission or diagnostic critical control units WARN: 6.1.7.3.b - Exhaust Emission Controller (61) provided more than one CAL ID and CVN pair in a single DM19 message

From the tool's ACII log: image

battjt commented 1 year ago

Reevaluate after testing with 750 ms timeout change. Development needs a CAN log to continue.

ericthomasswenson commented 1 year ago

On 3.1.4 here is a related if not identical complaint.

Global response for SA 61 is missing.

Start Test 1.7 - DM19: Calibration information 08:49:38.4474 Global DM19 Request 08:49:38.4505 18EAFFF9 [3] 00 D3 00 (TX) 08:49:38.6273 1CD3FF27 [20] 23 66 70 E6 49 31 33 58 58 58 58 5F 47 31 30 30 30 47 31 30 DM19 from Management Computer #1 (39): CAL ID of I13XXXX_G1000G10 and CVN of 0xE6706623

08:49:39.4739 1CD3FF00 [140] E2 58 7B B4 45 43 55 2D 53 57 20 6E 75 6D 62 65 72 00 00 00 3F 6C 00 00 35 38 34 33 53 30 30 36 2E 30 30 35 00 00 00 00 15 2B DF 8C 53 43 41 4E 4F 78 4E 2D 30 34 34 30 41 54 49 32 61 59 D4 FB 53 43 41 4E 4F 78 4E 2D 30 34 34 30 41 54 4F 32 15 2B DF 8C 53 43 41 4E 4F 78 4E 2D 30 34 34 30 41 54 49 32 8A FC 90 37 50 4D 53 50 2A 31 32 2A 33 35 30 2A 41 31 30 30 C2 90 45 C4 30 31 38 38 30 30 36 31 30 51 20 20 20 20 20 00 DM19 from Engine #1 (0): [ CAL ID of ECU-SW number and CVN of 0xB47B58E2 CAL ID of 5843S006.005 and CVN of 0x00006C3F CAL ID of SCANOxN-0440ATI2 and CVN of 0x8CDF2B15 CAL ID of SCANOxN-0440ATO2 and CVN of 0xFBD45961 CAL ID of SCANOxN-0440ATI2 and CVN of 0x8CDF2B15 CAL ID of PMSP12350*A100 and CVN of 0x3790FC8A CAL ID of 018800610Q and CVN of 0xC44590C2 ]

WARN: 6.1.7.3.a - Total number of reported CAL IDs is > user entered value for number of emission or diagnostic critical control units WARN: 6.1.7.3.b - Engine #1 (0) provided more than one CAL ID and CVN pair in a single DM19 message FAIL: 6.1.7.2.b.ii - Engine #1 (0) CAL ID not formatted correctly (contains non-printable ASCII) FAIL: 6.1.7.2.b.ii - Engine #1 (0) CAL ID not formatted correctly (contains non-printable ASCII) FAIL: 6.1.7.2.b.ii - Engine #1 (0) CAL ID not formatted correctly (contains non-printable ASCII) 08:49:39.4847 Destination Specific DM19 Request to Engine #1 (0) 08:49:39.4882 18EA00F9 [3] 00 D3 00 (TX) 08:49:39.5260 1CD3F900 [140] E2 58 7B B4 45 43 55 2D 53 57 20 6E 75 6D 62 65 72 00 00 00 3F 6C 00 00 35 38 34 33 53 30 30 36 2E 30 30 35 00 00 00 00 15 2B DF 8C 53 43 41 4E 4F 78 4E 2D 30 34 34 30 41 54 49 32 61 59 D4 FB 53 43 41 4E 4F 78 4E 2D 30 34 34 30 41 54 4F 32 15 2B DF 8C 53 43 41 4E 4F 78 4E 2D 30 34 34 30 41 54 49 32 8A FC 90 37 50 4D 53 50 2A 31 32 2A 33 35 30 2A 41 31 30 30 C2 90 45 C4 30 31 38 38 30 30 36 31 30 51 20 20 20 20 20 00 DM19 from Engine #1 (0): [ CAL ID of ECU-SW number and CVN of 0xB47B58E2 CAL ID of 5843S006.005 and CVN of 0x00006C3F CAL ID of SCANOxN-0440ATI2 and CVN of 0x8CDF2B15 CAL ID of SCANOxN-0440ATO2 and CVN of 0xFBD45961 CAL ID of SCANOxN-0440ATI2 and CVN of 0x8CDF2B15 CAL ID of PMSP12350*A100 and CVN of 0x3790FC8A CAL ID of 018800610Q and CVN of 0xC44590C2 ] 08:49:39.5300 Destination Specific DM19 Request to Management Computer #1 (39) 08:49:39.5330 18EA27F9 [3] 00 D3 00 (TX) 08:49:39.5573 1CD3F927 [20] 23 66 70 E6 49 31 33 58 58 58 58 5F 47 31 30 30 30 47 31 30 DM19 from Management Computer #1 (39): CAL ID of I13XXXX_G1000G10 and CVN of 0xE6706623 08:49:39.5621 Destination Specific DM19 Request to Exhaust Emission Controller (61) 08:49:39.5644 18EA3DF9 [3] 00 D3 00 (TX) 08:49:39.6004 1CD3F93D [20] 4C 1C BE 7E 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 DM19 from Exhaust Emission C FAIL: 6.1.7.5.c - OBD ECU Exhaust Emission Controller (61) did not provide a response to Global query and did not provide a NACK for the DS query

End Test 1.7 - DM19: Calibration information

ericthomasswenson commented 1 year ago

The ASC log (provided separately) show back to back BAMs from two of three distributed devices. The response from 3Dh was omitted.

1.503674 1 18EAFFF9x Tx d 3 00 D3 00 1.504620 1 0CF00400x Rx d 8 00 7D 7D 00 00 FF FF 93 1.504911 1 0CF03900x Rx d 8 FF FF 00 00 FF FF FF FF 1.505191 1 18F0000Fx Rx d 8 50 7D 7D FF 00 7D FF 5F 1.506013 1 08FE6E0Bx Rx d 8 00 00 00 00 00 00 00 00 1.506293 1 18F0090Bx Rx d 8 A1 7B 60 97 7D CF 7D 7D 1.511505 1 0CF00203x Rx d 8 CC 00 00 FF F4 00 00 03 1.511788 1 0CF02903x Rx d 8 89 74 7C FF FF FF FF FF 1.514045 1 18FF7527x Rx d 8 20 4E 88 13 FF 8F F8 FF 1.514617 1 10FE6F00x Rx d 8 FF FF FF FF FF FF FF FF 1.514910 1 0C0A2700x Rx d 8 FF FF FF FF FF FF FF FF 1.515228 1 0CF00A00x Rx d 8 00 00 00 00 FF FF 00 00 1.515490 1 18ECFF00x Rx d 8 20 8C 00 14 FF 00 D3 00 1.515781 1 18FDA400x Rx d 8 FF FF FF FF FF FF FC FF 1.516053 1 18F0090Bx Rx d 8 A1 7B 60 97 7D CF 7D 7D 1.516345 1 18FFAD00x Rx d 8 2C 00 00 F8 00 00 9F E2 1.517956 1 18ECFF27x Rx d 8 20 14 00 03 FF 00 D3 00 1.520856 1 18ECFF3Dx Rx d 8 20 14 00 03 FF 00 D3 00 1.521149 1 18F0FB00x Rx d 8 FF FF 00 00 00 00 FF FF 1.521497 1 0CF00203x Rx d 8 CC 00 00 FF F4 00 00 03 1.521784 1 0CF02903x Rx d 8 27 75 7C FF FF FF FF FF 1.523446 1 0CFF7427x Rx d 8 00 00 9C 68 FF FF 4C 6E 1.524056 1 0CF00327x Rx d 8 FF FF FF 00 FF FF FF FF 1.524769 1 0CF00400x Rx d 8 00 7D 7D 00 00 FF FF 93 1.525059 1 0CF02300x Rx d 8 00 00 FF FF FF FF FF FF 1.525349 1 0CF03900x Rx d 8 FF FF 00 00 FF FF FF FF

ericthomasswenson commented 1 year ago

See BobH 3.1.5 ASC for 2nd instance / root

battjt commented 1 year ago

I think I finally figured it out. It is related to the key state check that was failing in 3.1.4.

A process copies packets from the RP1210 adapter into queue A. Packets are processed from A through the J1939 TP logic into B. The order of the messages are maintained based on the BAM message, not the completion. If a TP message is progressing, it may take longer than the initial timeout; that is that the timeout is based on the initial TP control packet time and additional interpacket timing, not a single overall time. This is represented by putting an incomplete message in B that application access will block on until the packet is completely received. In this way the application will process a large DM19 before receiving a short DM19 that had a later TP BAM message but ended sooner. The bug is that a process that is monitoring queue B would stop once the overall timeout was reached, so short messages after a long message would be lost.

I changed the logic of "J1939 requestGlobal" to recognize all responses received during the entire period that any response was still in play.

So instead of

            while (System.currentTimeMillis() < end) {

it is now

            while (nextItem.isReady() || System.currentTimeMillis() < end) {

In a perfect world, the timestamp on the packet would use the same clock as the operating system and we could be smarter about this. We don't have that luxery with RP1210; the timestamp is from the adapter and it skews badly compared to the application.

The downside of this is that there will be more false positive late responses. If there are false responses (responses to other requestors) that occur late, it will still be reported as late, there is just a better chance that we will see false late responses.

The change broke one of our tests, that I think was incorrect anyway.