[KeithMerg]

VersionedValue: never refuse or drop an owner's change

VersionedValueListener.setFromOwner and VersionedValue.set(T) took a new version and then stored the value as two separate steps. A set on another thread could take a later version in between and be stored first; for example, a BitProducerConsumer applying a message from the network. The earlier set was then refused as out of date. Nothing was stored, no listener was told, and for a BitProducerConsumer no event report was sent for the owner's change.

In JMRI this can leave an OlcbSensor in a state that differs from the bit and from the bus after quick changes. OlcbSensor.setKnownState shows the requested state after calling setFromOwner, even when the set was refused. It is the likely cause of intermittent failures of OlcbSensorTest.testSensor.

The change

• One step. Taking the version and storing the value are now one step, under the VersionedValue's lock. Listeners are still called after the lock is released, as before.
• Overtaken changes. One smaller window remained. The listener that sends a BitProducerConsumer's event reports also sets the values received from the network. If such a value is stored after the owner's change but before the listener is told of it, the listener sees a value newer than the owner's and skips the owner's change, so again no report is sent. VersionedValueListener(parent, true) is a new opt-in mode in which the listener is told of every change made by someone else, with the value of that change, even if it has set a newer value since. Notifications now carry the version and the listener that made the change (VersionedValue.Change), so a listener can tell its own changes apart. BitProducerConsumer uses this mode for its reporting listener. The default mode is unchanged.
• Loopback unchanged. Messages a BitProducerConsumer sends still come back to it and set the value, as before. They come back as they leave the send queue, which is where they take their place among the messages heard from the bus, so applying them keeps the node in step with the order of messages on the bus. (The first version of this PR ignored them, which broke that; thanks to @balazsracz for pointing it out.)

TractionThrottle's speed and function updaters follow the same pattern as BitProducerConsumer: one listener sends, and also sets the values received from the network. They are left alone here and could use the new mode in a follow-up.

Tests

• Race tests. Three VersionedValueTest tests force the interleaving: the other set runs after the owner has taken its version, and the test decides by the other thread's state and the lock it is waiting for, not by time. They cover setFromOwner, setFromOwnerWithForceNotify and set(T), and each fails on master.
• Listener modes. testEveryChangeListenerToldOfOvertakenChange shows that a listener in the new mode is told of an overtaken change. testDefaultListenerSkipsOvertakenChange shows the default mode still skips it. testEveryChangeListenerSkipsOwnChanges covers the basic behaviour of the new mode.
• Bus order. testFollowsBusOrderWhenRemoteReportHeardBeforeOursIsSent (the case raised in review) and testOwnReportsSetValueInBusOrder check that reports from another node, and our own reports as they come back, set the value in bus order. Both pass on master and with this change; the first version of this PR failed both.
• Other objects. testOtherLocalObjectSeesEventReports checks that another object on the same interface follows the reports.

How this was tested

Maven Central can't be reached from where I built this, so the library was built with javac --release 8, as the library's CI does, and the tests were run with JUnit 4 and Mockito 5.

• Full suite: all 629 tests pass with this change (620 on master), under Xvfb.
• Under load: the full suite was run 20 times in shuffled class order with every core busy and -Xmx512m -Xss512k -XX:ActiveProcessorCount=2. 18 of the 20 runs were clean. The other two each had one failure in a timing test that doesn't use VersionedValue: MemoryConfigurationServiceInterfaceTest.testReadWithTimeout and TimeBroadcastGeneratorTest.testMidnightRolloverAfterStart. Under the same load, run 50 times on its own on master and with this change, the first passed 50 of 50 both ways; the second failed 10 of 50 on master and 14 of 50 with this change.
• Repeats: VersionedValueTest and BitProducerConsumerTest passed 200 runs of 200 under the same load.

JMRI master (718a32a) was built in full and its tests run against this library in place of lib/openlcb.jar:

• jmri.jmrix.openlcb package: 586 of 586 pass, both with this change and with OpenLCB_Java master.
• OlcbSensorTest.testSensor, one JVM per run, under the same CPU load: with OpenLCB_Java master, 3 of 80 runs failed. Each failure was a 10-second timeout: after a setState the sensor never reached the new state, so the change was lost, not just late. With this change, 0 of 80 runs failed.
• A probe test, not part of this change: it sets an OlcbSensor ACTIVE and straight away INACTIVE, waits for the send queue to empty, then checks that the sensor, its BitProducerConsumer value and the last event report sent all say INACTIVE. With OpenLCB_Java master, 7 of 92,000 cycles were wrong, all the same way: the sensor showed INACTIVE, the value was still on, and no report for INACTIVE had been sent. With this change, 0 of 92,000.

[balazsracz]

How do you know that the OlcbSensor will end up in the same state that another device that is observing the bus traffic? Ultimately what matters is the ordering of the messages on the bus (e.g. on CAN-bus).

…

Message ID: ***@***.***>

[KeithMerg]

You're right, and thank you: that was a hole in the first version. The loopback is delivered as our message leaves the send queue, which is where it takes its place among the messages we hear from the bus. If another node's report was heard between the owner's change and our message going out, the bus would end at our value, but by ignoring our own report we would have stayed at theirs.

Looking at it again, the replay I described is just the node following bus order, and isn't a fault. The real fault is a lost write. VersionedValueListener.setFromOwner (and VersionedValue.set(T)) took a new version and then stored the value as two separate steps. A loopback on another thread could take a later version in between and be stored first. The owner's change was then refused as out of date, so nothing was stored and no report was sent. In JMRI, OlcbSensor.setKnownState still shows the requested state afterwards, so the sensor disagrees with the bit and with the bus.

I've replaced the commit with one that fixes that and leaves the loopback handling as it was:

• Taking the version and storing the value are now one step, under the VersionedValue's lock. Listeners are still called after the lock is released.
• One smaller window remained. The listener that sends BitProducerConsumer's reports also sets the values from the network. If one of those is stored after the owner's change but before the listener has been told of it, the listener sees a newer value and skips the owner's change. There's now an opt-in mode, new VersionedValueListener<>(value, true), that tells the listener of every change made by someone else. BitProducerConsumer uses it. Notifications carry the version and the listener that made the change, so a listener can tell its own changes apart.
• New tests force each interleaving by thread state, not by timing, and fail without the change. A BitProducerConsumer test covers your case: a report from another node heard while ours is still queued, after which we end at our own value, in bus order.
• Against JMRI, a quick ACTIVE then INACTIVE on an OlcbSensor lost the INACTIVE (value still on, nothing sent) 7 times in 92,000 cycles with the current library, and never with this change. JMRI's openlcb tests all pass either way. The details are in the PR description.

TractionThrottle's speed and function updaters follow the same pattern (one listener sends, and also sets the values received from the network). I've left them alone here to keep this change focused, but they could use the new mode in a follow-up if you agree.

[balazsracz]

Do you, Keith Bruce, understand this code and the proposed changes? Did you read every line of code that is in this PR? Do you vouch for the correctness of these changes with your professional reputation?

... or am I, as a person, just having a conversation with your AI?

My question is what is your threading model. You are clearly changing the contract around this class. What is the new contract? What is the threading model behind the new contract? We can only evaluate a contract given a particular threading model. Could you contrast your assumed threading model with JMRI's threading model (as you seem to be coming with examples from JMRI)?

[KeithMerg]

I am a real person using power tools (AI) to help me fix an issue I'm having in JMRI. I was trying to be helpful but your tone suggests otherwise. I certainly did not intend to do harm or upset you.

On the threading model: your question found the gap in my case, so thank you.

OpenLCB_Java on its own (no loopback thread set): three threads can call into a BitProducerConsumer’s VersionedValue. The owner calls setFromOwner from any thread, messages from the network arrive on the receive thread, and our own messages come back on the send-queue thread. As I read the current contract, each set takes a version and is applied only if that version is newer than the current one, so a set that has been overtaken is dropped. setFromOwner takes its version and stores the value as two separate steps, so another thread can take and store a later version in between. The owner’s change is then dropped, along with its event report. My change assumed this multi-threaded model. It makes taking the version and storing the value one step, so sets are applied in the order their versions are taken, and adds a listener mode that reports every change. Those are the contract changes.

JMRI puts all of this on one thread. OlcbConfigurationManager sets the loopback thread to the layout thread, incoming CAN frames are handed out with invokeLater, and layout objects are changed on the layout thread. With one thread nothing can interleave, so the race above cannot happen there. The exception is code that runs on its own thread, such as scripts (AbstractAutomaton), which can set a sensor from outside the layout thread. I checked the layout-thread case: setting an OlcbSensor ACTIVE then INACTIVE on the layout thread lost nothing in 80,000 cycles with the current library. Doing the same from the JUnit thread lost the INACTIVE 3 times in 80,000.

OlcbSensorTest.testSensor (inherited from AbstractSensorTestBase) sets the sensor from the JUnit thread, outside JMRI’s model, and that is why it fails now and then. So my claim that this fixes a JMRI problem was wrong. That failure belongs on the JMRI side, and I’ll deal with it there.

If the script case needs fixing, I think it belongs in JMRI too, by having the OpenLCB beans hand their sets to the layout thread, not in a change to this library’s contract. So I’m closing this PR. Thank you for the careful review.

[balazsracz]

Keith,

I know you are a real person. I know that you are trying to be helpful. I know that you have good intentions. That was never the question. I also know that you are using AI, that was never the question either.

(1) The question you never answered is whether you have read and understood the code you sent me, and whether you vouch for it?

This is not a tone of voice question, but understanding what is the effort you have put into this solution. It might take you two minutes to copy-paste my reply into your AI. It takes me more than an hour to read changes of this complexity, especially so fundamental in nature. That is an hour that I spent not building my layout, not working on improvements I find important (possibly including your problem), or not spending with my family. We had two of those here, because your AI completely rewrote the changes upon the first cross-examination question.

(2) With your professional reputation on the line, as well as a person, do you think these two hours were well spent?

I, as a person, would love to have your answers to (1) and (2).

thanks,
Balazs

[KeithMerg]

Balazs,

(1) I read the change and thought it looked correct. I did not understand all of it. The design, the code and the tests were produced with AI tools; I directed the work, read the result and ran the tests, but I can't claim to have understood every line. So no, I don't vouch for it on my professional reputation, and if that's the standard for taking it, don't take it.

(2) Honestly, I don't know. I'm not paid for this, and nor are you. I use CBUS; this came up as an intermittent failure of OlcbSensorTest on one of my JMRI pull requests, and I chased it because the fault behind it is real and I thought I'd go the extra mile rather than leave it for someone else. The revised version took about four hours of my time plus paid-for AI, and this morning's review took another hour. I don't need to understand every part of a power tool to use it; I build up a sense of what it can be trusted with, and I'm still learning where that line is. On changing tack after your first question: you were right, and it would have been foolish to keep pushing a case I knew to be wrong. I don't want to waste your time. I also don't want someone else to spend theirs tracking down a bug that is this close to being resolved.

On the code, so nothing is left hanging and you need do nothing with it:

The change you reviewed as a4056ee is unchanged. Since then I have added a javadoc statement of the threading contract on VersionedValue and VersionedValueListener, and one test that pins down the ordering rule in it, to the same branch. The contract is: any thread may call any method; a set that takes its own version is stored and never refused; a set at a version requested earlier is refused if a newer one has been stored since; listeners are told after the lock is released, so sets made at the same time on two threads can notify out of version order; the default listener mode reads the current value when notified and is unaffected by that; the everyChange mode is told of each change in arrival order, and BitProducerConsumer's own reports coming back set the value in bus order.

One correction to my last comment: I said the race can only be reached from JMRI by scripts. That was wrong. Several JMRI subsystems set sensors and turnouts from their own threads without handing over to the layout thread, Dispatcher's automatic turnouts among them, so on a layout with OpenLCB items it can happen in ordinary use.

I'm not asking you to review it again. It's on the branch if the library ever wants it, and I'm happy to open a short issue with the one deterministic failing test instead, so the record is small and the decision stays with you. If neither is wanted, that's fine too.

Keith

[balazsracz]

Ken,

Do I understand correctly, that the only problem you were facing was an occasional test failure in OlcbSensorTest? You did not receive a user report from JMRI claiming a problem and you did not experience a problem on your layout (as you are not an OpenLCB user yourself)?

For test flakiness the first thing to look at usually is whether the test infrastructure correctly implements what the production code does. It is often not the case, and the fix should be in the test / test infrastructure.

If you had started an email thread with the problem you're facing, we could have found a much better solution in a lot less time.

Thanks,
Balazs

[KeithMerg]

Balazs,

Yes, that's right on all three. The only problem was an intermittent failure
of OlcbSensorTest.testSensor on one of my JMRI pull requests. There was no
user report, and I'm not an OpenLCB user, so I haven't seen it on a layout.

You're right about where the fault is, too. JMRI's rule is that layout
objects are changed on the layout thread, and that code on other threads
hands its calls over with ThreadingUtil. JMRI's OpenLCB support is built on
that: it puts the loopback and incoming frames on the layout thread. With
every set made there, the current library lost nothing in 80,000 cycles.
testSensor sets the sensor from the JUnit thread, which breaks that rule, and
so do a few JMRI subsystems in production (Dispatcher's automatic turnouts,
the JSON server, WiThrottle, LogixNG formula functions). Those are JMRI bugs
by JMRI's own rule, so I'll fix the test in JMRI and report the subsystems
there. Nothing is needed in the library.

I'm sorry for the time this has taken you. Part of how it went wrong is
worth saying: when I compared fixing the library with fixing the JMRI code
that breaks the threading rule, I chose the library partly because fixing
the callers looked like a lot more work. That was the wrong reason. The fix
belongs where the fault is, however much work that turns out to be. And as
you say, an email first would have got there in a fraction of the time.

Thank you for your patience with it.

Keith