Equipment-and-Tool-Institute / j1939-84

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

Tool is skipping some key state related popups #1189

Closed markmorrisoncummins closed 1 year ago

markmorrisoncummins commented 1 year ago

We have experienced some key/engine state instructions skipped by the tool. The message is not displayed and the tool continues as if the key/engine is in the correct state, even if it is not. This usually shows up in the tool log as unexpected initial and/or final engine speeds. The part it occurs does not appear to be consistent, but it does always seem to be related to the key/engine state instructions. Unsure what releases have this issue, but we've noticed it frequently in the 3.1.x releases.

Here is an example from a 3.1.4 log in 6.6.11 where the first key off popup was skipped:

Start Test 6.11 - Complete fault A three trip countdown cycle 3
Initial Engine Speed = 749.875 RPMs
Final Engine Speed = 748.75 RPMs <--- This should be key off, but tool continued without instructing key off.
Initial Engine Speed = 748.375 RPMs
Final Engine Speed = 159.875 RPMs <--- tool correctly waited for key on, engine off (engine speed <= 300)
Initial Engine Speed = 750.375 RPMs
Final Engine Speed = Key Off
Initial Engine Speed = Key Off
Final Engine Speed = 0.0 RPMs

And an expected sequence from a 3.0.13 log:

Start Test 6.11 - Complete fault A three trip countdown cycle 3
Initial Engine Speed = 650.5 RPMs
Final Engine Speed = Key Off
Initial Engine Speed = Key Off
Final Engine Speed = 0.0 RPMs
Initial Engine Speed = 652.875 RPMs
Final Engine Speed = Key Off
Initial Engine Speed = Key Off
Final Engine Speed = 0.0 RPMs

I did some poking around and it seems like this getCurrentKeyState() != requestedKeyState returning false at https://github.com/Equipment-and-Tool-Institute/j1939-84/blob/5949042f5aedf7f509e962e8da559974d231ac6b/src/org/etools/j1939_84/controllers/StepController.java#L180 is consistent with the behavior we're seeing, but as far as I can tell EEC1 was broadcast correctly and on time throughout.

I can provide a couple CAN traces on request from tests that exhibit this issue.

markmorrisoncummins commented 1 year ago

To be clear, this is referring to part 6, test 11. Section 6.6.11 in the J1939-84 document.

I also want to note that I don't think there is anything special about part 6 test 11. This issue has occurred in other parts and I suspect has the potential to happen any time there is a key switch or engine speed instruction.

battjt commented 1 year ago

I think it is related to the tool missing the EEC1 packet and incorrectly reporting key off. Please send the log and specify which adapter was used in collecting the log and which adapter was with the tool. The fix may be as simple as waiting longer for the broadcast of EEC1 (currently 300 ms).

markmorrisoncummins commented 1 year ago

Logs sent via email. The .asc files are the ones auto-generated by the j1939-84 tool. One was using a PEAK adapter and skipped a key off popup in part 6. The other was using INLINE 7 and skipped a key on popup in the part 11-12 transition.

ericthomasswenson commented 1 year ago

Transitions from off to on will delay receipt of EEC1 while the POST is running, waiting longer sounds like a good idea

battjt commented 1 year ago

I expect that the false transition from KOEx to OFF is an implementation issue with how TP is handled in the tool. At the application level, packets are sequenced byt the first packet of the TP session, so EEC1 packets may be delayed while waiting on a BAM (FECA for example) that may take longer. (Most of the timeout logic is handled at a lower level and does not have this issue.) We are increasing the wait from 300 ms to 1.2 s to accomodate this.

The logs also indicate "skipped a key on popup in the part 11-12 transition". I don't have an explaination for that yet.

ericthomasswenson commented 1 year ago

Jacob’s perception that this is more frequent in 3.1 version than 3.0.

Users will pay more attention to this for the next release.

One user has no recollection of observing the behavior.

jacobbosch-cummins commented 1 year ago

2 tests were completed with 3.1.5 and this issue was not observed. I will try a few more later this week.

jacobbosch-cummins commented 1 year ago

In total, I've completed 3 tests with 3 different datalink adapters on 3.1.5 and the issue was not observed. I propose closing this issue.

ericthomasswenson commented 1 year ago

Not observed in 3.1.5