From 2dcc1602a2004f90872b08a5004a1505cf4e32e4 Mon Sep 17 00:00:00 2001 From: jadamcrain Date: Thu, 15 Oct 2026 19:49:14 -0700 Subject: [PATCH] Make the timing tolerance an option: test.timingToleranceMs dnp3c allowed two fixed tolerances on the times it measures: 500 ms on the intervals it times, e.g. unsolicited retries, and 200 ms past each timeout it waits on. Neither could be changed, so a run on a busy machine could fail a timing check with no way to allow for it (#93). Both are now test.timingToleranceMs, 500 ms by default. Only the steps that expect no message wait longer for it: a read that gets its message returns as soon as it arrives. --- CHANGELOG.md | 1 + docs/manual-testing.md | 4 ++ .../conformance/api/options/TestOptions.scala | 15 ++++- .../conformance/application/TestRunner.scala | 1 + .../common/UnconfirmedResponse.scala | 9 +-- .../common/UnsolicitedResponseSteps.scala | 60 +++++++++++-------- .../conformance/v27/Procedure8_11_2_1.scala | 15 ++--- .../conformance/v27/Procedure8_11_2_5.scala | 3 +- .../conformance/v27/Procedure8_11_2_6.scala | 5 +- .../conformance/v27/Procedure8_9_2_2.scala | 4 +- .../dnp3c/conformance/v31r1/Network.scala | 9 +-- .../dnp3c/dnp3/DefaultTestDriver.scala | 4 +- .../io/stepfunc/dnp3c/dnp3/TestDriver.scala | 3 - .../conformance/common/TimedActionTest.scala | 11 ++-- .../common/UnsolicitedChecksTest.scala | 8 ++- .../conformance/v27/PrimaryFramesTest.scala | 1 + .../v27/Procedure8_11_2_1Test.scala | 8 +-- .../conformance/v27/SecondFragmentTest.scala | 2 +- .../conformance/v27/SilenceWaitsTest.scala | 2 +- .../dnp3c/dnp3/DefaultTestDriverTest.scala | 1 + .../dnp3c/dnp3/NetworkDriverTest.scala | 3 +- 21 files changed, 101 insertions(+), 68 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index c46ec67..86d0c17 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -6,6 +6,7 @@ - **Serial and UDP**, as well as TCP, including 3.1 rev 1's network, multi-drop and collision avoidance tests. - **Exclusions:** leave a procedure out of a run with a reason, e.g. for a known gap in the device. The report shows it as not run, apart from skipped procedures, with its reason. - **Reports** say why each procedure was skipped, flag the procedures that pass with warnings, where the device should probably change something, and name the revision and subset level. +- **Timing tolerance:** `test.timingToleranceMs` (500 ms by default) sets how far the times dnp3c measures may be off, e.g. for a busy machine or a slow network. It replaces two fixed allowances, of 500 ms for timed intervals and 200 ms past each timeout, so the steps that expect no message now wait 300 ms longer by default. - The runnable jar and the CLI zip list the licenses of the dependencies they bundle. ### Upgrading from 0.1.0 diff --git a/docs/manual-testing.md b/docs/manual-testing.md index ea2d8dd..016e802 100644 --- a/docs/manual-testing.md +++ b/docs/manual-testing.md @@ -45,6 +45,10 @@ Every command that reads the configuration checks the whole file first, and list `dnp3c -options` prints every option and its default without writing a file. +### Timing + +The tests that time the DUT, e.g. its unsolicited retries in 8.11, measure on the machine running dnp3c, so a busy machine or a slow network can make the DUT look early or late. `test.timingToleranceMs` (500 ms by default) is how far off those measurements may be, both ways: how long past a timeout dnp3c waits for a message, and how far an interval it times may be from the one expected. Run the timing tests on a machine that isn't busy with other work. If one fails under load, rerun it before treating it as a device problem, or raise the tolerance. A larger tolerance only makes the steps that expect no message wait longer: a step that gets its message moves on as soon as it arrives. + ## Choose the revision dnp3c can hold more than one revision of the certification procedure, and every command that uses procedures needs the one to use, given with `-rev`. Revisions number their procedures differently, so `-rev` decides what an id like 8.6.5.4 means. `dnp3c -revs` lists the revisions: diff --git a/src/main/scala/io/stepfunc/dnp3c/conformance/api/options/TestOptions.scala b/src/main/scala/io/stepfunc/dnp3c/conformance/api/options/TestOptions.scala index df29e8d..cf8fe6f 100644 --- a/src/main/scala/io/stepfunc/dnp3c/conformance/api/options/TestOptions.scala +++ b/src/main/scala/io/stepfunc/dnp3c/conformance/api/options/TestOptions.scala @@ -27,6 +27,18 @@ object TestOptions extends OptionGroup { None ) + val timingToleranceMs: IntegerOption = OptionTypes.integer( + this, + "timingToleranceMs", + 500, + "How far a time the harness measures may be off, in ms, both ways: how late a message may arrive past a timeout " + + "the harness waits on, and how far an interval it times may be from the one expected, e.g. an unsolicited " + + "retry from the confirm timeout. A larger value is more forgiving of a slow network or a busy machine, both " + + "early and late. For the serial line's own timing, see serial.timingToleranceMs", + Some(0), + None + ) + val exclude: ExclusionsOption = OptionTypes.exclusions( this, "exclude", @@ -40,6 +52,7 @@ object TestOptions extends OptionGroup { def prefix: String = "test" def description: String = "Options for the test harness itself" - def options: List[TestOption] = List(outputDirectory, deviceUnderTest, manualActionWindowMs, exclude) + def options: List[TestOption] = + List(outputDirectory, deviceUnderTest, manualActionWindowMs, timingToleranceMs, exclude) } diff --git a/src/main/scala/io/stepfunc/dnp3c/conformance/application/TestRunner.scala b/src/main/scala/io/stepfunc/dnp3c/conformance/application/TestRunner.scala index eed25be..900fc41 100644 --- a/src/main/scala/io/stepfunc/dnp3c/conformance/application/TestRunner.scala +++ b/src/main/scala/io/stepfunc/dnp3c/conformance/application/TestRunner.scala @@ -51,6 +51,7 @@ private[application] object ProcedureEnvironment { options.get(LinkOptions.timeout), options.get(OutstationOptions.responseTimeout), options.get(UnsolicitedOptions.unsolicitedConfirmTimeoutMs), + options.get(TestOptions.timingToleranceMs), policies = policies ) } diff --git a/src/main/scala/io/stepfunc/dnp3c/conformance/common/UnconfirmedResponse.scala b/src/main/scala/io/stepfunc/dnp3c/conformance/common/UnconfirmedResponse.scala index 016a8bf..1e4b7ef 100644 --- a/src/main/scala/io/stepfunc/dnp3c/conformance/common/UnconfirmedResponse.scala +++ b/src/main/scala/io/stepfunc/dnp3c/conformance/common/UnconfirmedResponse.scala @@ -5,7 +5,6 @@ package io.stepfunc.dnp3c.conformance.common import io.stepfunc.dnp3c.conformance.api._ import io.stepfunc.dnp3c.conformance.common.GenericSteps.validateUnsolicitedResponse -import io.stepfunc.dnp3c.conformance.common.UnconfirmedResponse.timingToleranceMs import io.stepfunc.dnp3c.dnp3.app._ import io.stepfunc.dnp3c.dnp3.{ ActionTiming, AutoConfirm, Comment, MessageValidation, Requests, TestDriver } import io.stepfunc.dnp3c.dnp3.DeferredCheck @@ -13,7 +12,7 @@ import io.stepfunc.dnp3c.dnp3.DeferredCheck // A response left unconfirmed, to check that the DUT holds back what it would otherwise send (e.g. the answer to a // READ) until the response is confirmed or its confirm timeout expires. Timing is measured from when the response // was received, on the driver's clock. -class UnconfirmedResponse(confirmTimeoutMs: Int) { +class UnconfirmedResponse(confirmTimeoutMs: Int, timingToleranceMs: Int) { private var response: Option[Message] = None private var receivedAtMs = 0L @@ -118,9 +117,3 @@ class UnconfirmedResponse(confirmTimeoutMs: Int) { } } } - -object UnconfirmedResponse { - // Timing tolerance, e.g. between the DUT sending and us receiving a response. Adopted from the measurement - // accuracy 8.11.2.1 allows for unsolicited retries. - private[conformance] val timingToleranceMs = 500 -} diff --git a/src/main/scala/io/stepfunc/dnp3c/conformance/common/UnsolicitedResponseSteps.scala b/src/main/scala/io/stepfunc/dnp3c/conformance/common/UnsolicitedResponseSteps.scala index b508382..ccac77c 100644 --- a/src/main/scala/io/stepfunc/dnp3c/conformance/common/UnsolicitedResponseSteps.scala +++ b/src/main/scala/io/stepfunc/dnp3c/conformance/common/UnsolicitedResponseSteps.scala @@ -4,7 +4,7 @@ package io.stepfunc.dnp3c.conformance.common import io.stepfunc.dnp3c.conformance.api._ -import io.stepfunc.dnp3c.conformance.api.options.{ SupportOptions, UnsolicitedOptions } +import io.stepfunc.dnp3c.conformance.api.options.{ SupportOptions, TestOptions, UnsolicitedOptions } import io.stepfunc.dnp3c.dnp3.link.FrameValidator import io.stepfunc.dnp3c.conformance.common.GenericSteps._ import io.stepfunc.dnp3c.conformance.common.Validations._ @@ -20,14 +20,17 @@ object UnsolicitedResponseSteps { // how long the DUT can take to send an unsolicited response to new events: its hold-off time, and any wait for the // confirmation of an earlier response - private def eventsTimeoutMs(holdOffMs: Int, unsolConfirmTimeoutMs: Int): Int = - holdOffMs + unsolConfirmTimeoutMs + TestDriver.readToleranceMs + private def eventsTimeoutMs(holdOffMs: Int, unsolConfirmTimeoutMs: Int, toleranceMs: Int): Int = + holdOffMs + unsolConfirmTimeoutMs + toleranceMs // no unsolicited response to new events: wait as long as the DUT could take to send one - private[conformance] def expectNoEventsUnsolicited(holdOffMs: Int, unsolConfirmTimeoutMs: Int): TestStep = - expectNoUnsolicitedResponse(Some(eventsTimeoutMs(holdOffMs, unsolConfirmTimeoutMs))) + private[conformance] def expectNoEventsUnsolicited( + holdOffMs: Int, + unsolConfirmTimeoutMs: Int, + toleranceMs: Int): TestStep = + expectNoUnsolicitedResponse(Some(eventsTimeoutMs(holdOffMs, unsolConfirmTimeoutMs, toleranceMs))) - private def expectEventsUnsolicited(holdOffMs: Int, unsolConfirmTimeoutMs: Int)( + private def expectEventsUnsolicited(holdOffMs: Int, unsolConfirmTimeoutMs: Int, toleranceMs: Int)( autoConfirm: AutoConfirm, validation: MessageValidation = MessageValidation.none): TestStep = expectUnsolicitedResponse( @@ -35,7 +38,7 @@ object UnsolicitedResponseSteps { FrameValidator.none, withEvents(validation), LinkOverride.default, - Some(eventsTimeoutMs(holdOffMs, unsolConfirmTimeoutMs))) + Some(eventsTimeoutMs(holdOffMs, unsolConfirmTimeoutMs, toleranceMs))) // a response to new events carries them: checks that compare it with other responses would otherwise pass on a // response without any @@ -49,13 +52,17 @@ object UnsolicitedResponseSteps { * tester) is armed first and acts within actionWindowMs, so the harness is already reading when the DUT responds, * and times the response from when it actually arrives. */ - private[common] def generateAndExpectEvents(holdOffMs: Int, unsolConfirmTimeoutMs: Int, actionWindowMs: Int)( + private[common] def generateAndExpectEvents( + holdOffMs: Int, + unsolConfirmTimeoutMs: Int, + toleranceMs: Int, + actionWindowMs: Int)( autoConfirm: AutoConfirm, validation: MessageValidation = MessageValidation.none): TestStep = new TestStep { override def description: List[Comment] = PluginSteps.generateUnsolicitedEvents().description ++ - expectEventsUnsolicited(holdOffMs, unsolConfirmTimeoutMs)(autoConfirm, validation).description + expectEventsUnsolicited(holdOffMs, unsolConfirmTimeoutMs, toleranceMs)(autoConfirm, validation).description override def run(driver: TestDriver): List[DeferredCheck] = { val action = driver.reporter.plugin.generateUnsolicitedEvents( @@ -74,7 +81,7 @@ object UnsolicitedResponseSteps { FrameValidator.none, withEvents(validation), LinkOverride.default, - Some(eventsTimeoutMs(holdOffMs, unsolConfirmTimeoutMs) + extraMs), + Some(eventsTimeoutMs(holdOffMs, unsolConfirmTimeoutMs, toleranceMs) + extraMs), noResponse ).run(driver) } @@ -89,7 +96,8 @@ object UnsolicitedResponseSteps { options.get(data.support), otherSupportedClasses(data, options), options.get(UnsolicitedOptions.unsolicitedConfirmTimeoutMs), - options.get(UnsolicitedOptions.holdOffMs) + options.get(UnsolicitedOptions.holdOffMs), + options.get(TestOptions.timingToleranceMs) ) } @@ -104,8 +112,9 @@ object UnsolicitedResponseSteps { supportsClass: Boolean, otherClasses: List[EventClass], unsolConfirmTimeoutMs: Int, - holdOffMs: Int): List[LabeledStep] = { - val unconfirmed = new UnconfirmedResponse(unsolConfirmTimeoutMs) + holdOffMs: Int, + toleranceMs: Int): List[LabeledStep] = { + val unconfirmed = new UnconfirmedResponse(unsolConfirmTimeoutMs, toleranceMs) val eventClass = data.eventClass val classVariation = data.variation // step 12: a retry carries at least the events of the response it repeats; analog events may carry current values, @@ -121,14 +130,14 @@ object UnsolicitedResponseSteps { 3 --> (if (supportsClass) PluginSteps.generateClassEvents(eventClass) else describe(s"Device cannot generate Class ${classVariation.clazz} data")), - 4 --> expectNoEventsUnsolicited(holdOffMs, unsolConfirmTimeoutMs), + 4 --> expectNoEventsUnsolicited(holdOffMs, unsolConfirmTimeoutMs, toleranceMs), 5 --> send(enableUnsolicitedResponses(Sequence.one, classVariation)), 6 --> expectNullResponse(Sequence.one) ) val steps7to15 = if (supportsClass) List( // the retries are timed from this response and the next, so a manual answer here waits until the steps are done - (7 to 10) --> expectEventsUnsolicited(holdOffMs, unsolConfirmTimeoutMs)( + (7 to 10) --> expectEventsUnsolicited(holdOffMs, unsolConfirmTimeoutMs, toleranceMs)( unconfirmed.hold, PluginValidations.verifyOldAndNewClassEvents(eventClass).deferrable && recorder.record), (11 to 13) --> unconfirmed.expectRetry(sameEvents.deferrable && recorder.record, AutoConfirm.Wrong), @@ -140,7 +149,7 @@ object UnsolicitedResponseSteps { val steps16to17 = List( 16 --> PluginSteps.generateClassEvents(otherClasses), - 17 --> expectNoEventsUnsolicited(holdOffMs, unsolConfirmTimeoutMs) + 17 --> expectNoEventsUnsolicited(holdOffMs, unsolConfirmTimeoutMs, toleranceMs) ) steps1to6 ++ steps7to15 ++ steps16to17 @@ -169,21 +178,22 @@ object UnsolicitedResponseSteps { appConfirmTimeoutMs: Int, holdOffMs: Int, tables: Validations.Tables, - actionWindowMs: Int): Iterable[LabeledStep] = { + actionWindowMs: Int, + toleranceMs: Int): Iterable[LabeledStep] = { val messageRecorder = new MessageRecorder val seq = MutableSequence.zero def expectEvents(autoConfirm: AutoConfirm, validation: MessageValidation = MessageValidation.none): TestStep = - expectEventsUnsolicited(holdOffMs, unsolConfirmTimeoutMs)(autoConfirm, validation) + expectEventsUnsolicited(holdOffMs, unsolConfirmTimeoutMs, toleranceMs)(autoConfirm, validation) def generateAndExpect(autoConfirm: AutoConfirm, validation: MessageValidation = MessageValidation.none): TestStep = - generateAndExpectEvents(holdOffMs, unsolConfirmTimeoutMs, actionWindowMs)(autoConfirm, validation) - val unconfirmedUnsolicited = new UnconfirmedResponse(unsolConfirmTimeoutMs) - val unconfirmedPolled = new UnconfirmedResponse(appConfirmTimeoutMs) + generateAndExpectEvents(holdOffMs, unsolConfirmTimeoutMs, toleranceMs, actionWindowMs)(autoConfirm, validation) + val unconfirmedUnsolicited = new UnconfirmedResponse(unsolConfirmTimeoutMs, toleranceMs) + val unconfirmedPolled = new UnconfirmedResponse(appConfirmTimeoutMs, toleranceMs) // an unsolicited retry comes within a confirm timeout, plus the tolerance expectRetry allows, of the response it // repeats, so no response in that window means no more retries; 8.11.2.5.9 only counts its retries, so it doesn't // check they come no sooner, as expectRetry does - val retryWindowMs = Some(unsolConfirmTimeoutMs + UnconfirmedResponse.timingToleranceMs) + val retryWindowMs = Some(unsolConfirmTimeoutMs + toleranceMs) def expectRetry(autoConfirm: AutoConfirm): TestStep = expectUnsolicitedResponse( autoConfirm, FrameValidator.none, @@ -329,7 +339,7 @@ object UnsolicitedResponseSteps { ) } - def offSteps(unsolConfirmTimeoutMs: Int, holdOffMs: Int): Iterable[LabeledStep] = { + def offSteps(unsolConfirmTimeoutMs: Int, holdOffMs: Int, toleranceMs: Int): Iterable[LabeledStep] = { List( 1 --> PluginSteps.enableUnsolicitedResponse(false), 2 --> PluginSteps.cyclePower, @@ -340,10 +350,10 @@ object UnsolicitedResponseSteps { 7 --> send(Requests.readClass123(Sequence.one)), 8 --> expectAtLeastOneResponse(Sequence.one), 9 --> PluginSteps.generateUnsolicitedEvents(), - 10 --> expectNoEventsUnsolicited(holdOffMs, unsolConfirmTimeoutMs), + 10 --> expectNoEventsUnsolicited(holdOffMs, unsolConfirmTimeoutMs, toleranceMs), 11 --> send(enableUnsolicitedResponses(Sequence.two)), 12 --> expectSingleResponse(Sequence.two, containing(IIN.FUNC_NOT_SUPPORTED)), - 13 --> expectNoEventsUnsolicited(holdOffMs, unsolConfirmTimeoutMs), + 13 --> expectNoEventsUnsolicited(holdOffMs, unsolConfirmTimeoutMs, toleranceMs), 14 --> send(disableUnsolicitedResponses(Sequence.three)), 15 --> expectSingleResponse(Sequence.three, containing(IIN.FUNC_NOT_SUPPORTED)) ) diff --git a/src/main/scala/io/stepfunc/dnp3c/conformance/v27/Procedure8_11_2_1.scala b/src/main/scala/io/stepfunc/dnp3c/conformance/v27/Procedure8_11_2_1.scala index 8b74f00..4824f94 100644 --- a/src/main/scala/io/stepfunc/dnp3c/conformance/v27/Procedure8_11_2_1.scala +++ b/src/main/scala/io/stepfunc/dnp3c/conformance/v27/Procedure8_11_2_1.scala @@ -4,11 +4,10 @@ package io.stepfunc.dnp3c.conformance.v27 import io.stepfunc.dnp3c.conformance.api._ -import io.stepfunc.dnp3c.conformance.api.options.{ LinkOptions, SupportOptions, UnsolicitedOptions } +import io.stepfunc.dnp3c.conformance.api.options.{ LinkOptions, SupportOptions, TestOptions, UnsolicitedOptions } import io.stepfunc.dnp3c.dnp3.link.FrameValidator import io.stepfunc.dnp3c.conformance.common.GenericSteps._ import io.stepfunc.dnp3c.conformance.common.UnconfirmedResponse -import io.stepfunc.dnp3c.conformance.common.UnconfirmedResponse.timingToleranceMs import io.stepfunc.dnp3c.conformance.common.UnsolicitedResponseSteps.expectNoEventsUnsolicited import io.stepfunc.dnp3c.conformance.common.Validations import io.stepfunc.dnp3c.dnp3.app._ @@ -22,7 +21,8 @@ object Procedure8_11_2_1 extends ProcedureDefinition { override protected def steps(options: OptionSource): Iterable[LabeledStep] = { val unsolConfirmTimeoutMs = options.get(UnsolicitedOptions.unsolicitedConfirmTimeoutMs) val holdOffMs = options.get(UnsolicitedOptions.holdOffMs) - val restartResponse = new UnconfirmedResponse(unsolConfirmTimeoutMs) + val toleranceMs = options.get(TestOptions.timingToleranceMs) + val restartResponse = new UnconfirmedResponse(unsolConfirmTimeoutMs, toleranceMs) val nullWithRestart = Validations.containing(IIN.DEVICE_RESTART) && Validations.isNull val originalAddress = options.get(LinkOptions.source) val otherMasterAddress = options.get(UnsolicitedOptions.otherMasterAddress) @@ -56,11 +56,11 @@ object Procedure8_11_2_1 extends ProcedureDefinition { // and TB2015-002a have the DUT defer the READ until the confirmation or its timeout. So step 24 accepts either: // an answer deferred to the startup response's confirm timeout, or one well before it, with a warning - 24 --> expectDeferrableAnswer(responseTimeoutMs(options), unsolConfirmTimeoutMs, restartResponse), + 24 --> expectDeferrableAnswer(responseTimeoutMs(options), unsolConfirmTimeoutMs, toleranceMs, restartResponse), (25 to 26) --> restartResponse.expectRetry(Validations.isNull, AutoConfirm.Wrong), (27 to 28) --> restartResponse.expectRetry(Validations.isNull, AutoConfirm.Yes), 29 --> PluginSteps.generateUnsolicitedEvents(), - 30 --> expectNoEventsUnsolicited(holdOffMs, unsolConfirmTimeoutMs) + 30 --> expectNoEventsUnsolicited(holdOffMs, unsolConfirmTimeoutMs, toleranceMs) ) } @@ -69,14 +69,15 @@ object Procedure8_11_2_1 extends ProcedureDefinition { private def expectDeferrableAnswer( responseTimeoutMs: Int, confirmTimeoutMs: Int, + timingToleranceMs: Int, unsolicitedResponse: UnconfirmedResponse): TestStep = new TestStep { private val read = expectAtLeastOneResponse(Sequence.one) - private val timeoutMs = responseTimeoutMs + confirmTimeoutMs + TestDriver.readToleranceMs + private val timeoutMs = responseTimeoutMs + confirmTimeoutMs + timingToleranceMs override def description: List[Comment] = s"The DUT may defer its response until the startup unsolicited response is confirmed or its confirm timeout " + s"expires, so wait up to $timeoutMs ms for it (the response timeout, the unsolicited confirm timeout and " + - s"${TestDriver.readToleranceMs} ms)" :: read.description + s"$timingToleranceMs ms)" :: read.description override def run(driver: TestDriver): List[DeferredCheck] = { driver.readAllResponses(Sequence.one, AutoConfirm.Yes, firstTimeoutMs = Some(timeoutMs)) diff --git a/src/main/scala/io/stepfunc/dnp3c/conformance/v27/Procedure8_11_2_5.scala b/src/main/scala/io/stepfunc/dnp3c/conformance/v27/Procedure8_11_2_5.scala index 60313a9..aa4824e 100644 --- a/src/main/scala/io/stepfunc/dnp3c/conformance/v27/Procedure8_11_2_5.scala +++ b/src/main/scala/io/stepfunc/dnp3c/conformance/v27/Procedure8_11_2_5.scala @@ -26,7 +26,8 @@ class UnsolicitedAndPolledResponses(retryLimit: OptionSource => RetryLimit) exte options.get(OutstationOptions.appConfirmTimeout), options.get(UnsolicitedOptions.holdOffMs), Validations.Tables(options), - options.get(TestOptions.manualActionWindowMs) + options.get(TestOptions.manualActionWindowMs), + options.get(TestOptions.timingToleranceMs) ) } } diff --git a/src/main/scala/io/stepfunc/dnp3c/conformance/v27/Procedure8_11_2_6.scala b/src/main/scala/io/stepfunc/dnp3c/conformance/v27/Procedure8_11_2_6.scala index 8522e7b..3ad87d9 100644 --- a/src/main/scala/io/stepfunc/dnp3c/conformance/v27/Procedure8_11_2_6.scala +++ b/src/main/scala/io/stepfunc/dnp3c/conformance/v27/Procedure8_11_2_6.scala @@ -4,7 +4,7 @@ package io.stepfunc.dnp3c.conformance.v27 import io.stepfunc.dnp3c.conformance.api._ -import io.stepfunc.dnp3c.conformance.api.options.{ SupportOptions, UnsolicitedOptions } +import io.stepfunc.dnp3c.conformance.api.options.{ SupportOptions, TestOptions, UnsolicitedOptions } import io.stepfunc.dnp3c.conformance.common.UnsolicitedResponseSteps object Procedure8_11_2_6 extends ProcedureDefinition { @@ -14,6 +14,7 @@ object Procedure8_11_2_6 extends ProcedureDefinition { override protected def steps(options: OptionSource): Iterable[LabeledStep] = { UnsolicitedResponseSteps.offSteps( options.get(UnsolicitedOptions.unsolicitedConfirmTimeoutMs), - options.get(UnsolicitedOptions.holdOffMs)) + options.get(UnsolicitedOptions.holdOffMs), + options.get(TestOptions.timingToleranceMs)) } } diff --git a/src/main/scala/io/stepfunc/dnp3c/conformance/v27/Procedure8_9_2_2.scala b/src/main/scala/io/stepfunc/dnp3c/conformance/v27/Procedure8_9_2_2.scala index 41ac2f2..b6a75eb 100644 --- a/src/main/scala/io/stepfunc/dnp3c/conformance/v27/Procedure8_9_2_2.scala +++ b/src/main/scala/io/stepfunc/dnp3c/conformance/v27/Procedure8_9_2_2.scala @@ -5,7 +5,7 @@ package io.stepfunc.dnp3c.conformance.v27 import io.stepfunc.dnp3c.conformance.v31r1.Rules import io.stepfunc.dnp3c.conformance.api._ -import io.stepfunc.dnp3c.conformance.api.options.{ OutstationOptions, SupportOptions } +import io.stepfunc.dnp3c.conformance.api.options.{ OutstationOptions, SupportOptions, TestOptions } import io.stepfunc.dnp3c.conformance.common.GenericSteps._ import io.stepfunc.dnp3c.conformance.common.UnconfirmedResponse import io.stepfunc.dnp3c.conformance.common.Validations._ @@ -21,7 +21,7 @@ object Procedure8_9_2_2 extends ProcedureDefinition { override protected def steps(options: OptionSource): Iterable[LabeledStep] = { val confirmTimeout = options.get(OutstationOptions.appConfirmTimeout) - val pending = new UnconfirmedResponse(confirmTimeout) + val pending = new UnconfirmedResponse(confirmTimeout, options.get(TestOptions.timingToleranceMs)) // past the application confirmation timeout: a second longer val pastConfirmTimeout = confirmTimeout + 1000 // inside the application confirmation timeout: half of it diff --git a/src/main/scala/io/stepfunc/dnp3c/conformance/v31r1/Network.scala b/src/main/scala/io/stepfunc/dnp3c/conformance/v31r1/Network.scala index 5ccfe3e..e1010c4 100644 --- a/src/main/scala/io/stepfunc/dnp3c/conformance/v31r1/Network.scala +++ b/src/main/scala/io/stepfunc/dnp3c/conformance/v31r1/Network.scala @@ -6,13 +6,14 @@ package io.stepfunc.dnp3c.conformance.v31r1 import java.net.{ ConnectException, InetAddress, InetSocketAddress, SocketTimeoutException } import io.stepfunc.dnp3c.conformance.api._ -import io.stepfunc.dnp3c.conformance.api.options.{ ChannelOptions, NetworkOptions, SupportOptions, UnsolicitedOptions } +import io.stepfunc.dnp3c.conformance.api.options.{ + ChannelOptions, NetworkOptions, SupportOptions, TestOptions, UnsolicitedOptions +} import io.stepfunc.dnp3c.conformance.api.options.NetworkOptions.isAddress import io.stepfunc.dnp3c.conformance.common.LinkSteps.{ expectFrame, sendLinkControl, withAnyControl } import io.stepfunc.dnp3c.conformance.common.GenericSteps.{ expectAtLeastOneResponse, expectNoUnsolicitedResponse, expectSingleResponse, expectUnsolicitedResponse, send } -import io.stepfunc.dnp3c.conformance.common.UnconfirmedResponse import io.stepfunc.dnp3c.conformance.common.GenericSteps.validateUnsolicitedResponse import io.stepfunc.dnp3c.conformance.common.Validations.{ isNull, without } import io.stepfunc.dnp3c.dnp3._ @@ -418,7 +419,7 @@ object Network { // a retry of an unconfirmed unsolicited response comes within the confirm timeout, give or take the tolerance private def retryWindow(options: OptionSource): Option[Int] = - Some(options.get(UnsolicitedOptions.unsolicitedConfirmTimeoutMs) + UnconfirmedResponse.timingToleranceMs) + Some(options.get(UnsolicitedOptions.unsolicitedConfirmTimeoutMs) + options.get(TestOptions.timingToleranceMs)) private val withEvents = MessageValidation.check("Verify that the response reports events") { m => if (m.headers.isEmpty) throw new Exception("The unsolicited response reports no events") @@ -479,7 +480,7 @@ object Network { LinkOverride.default, Some( options.get(UnsolicitedOptions.holdOffMs) + options.get(UnsolicitedOptions.unsolicitedConfirmTimeoutMs) + - UnconfirmedResponse.timingToleranceMs) + options.get(TestOptions.timingToleranceMs)) ), expectNoUnsolicitedResponse(retryWindow(options)) ) diff --git a/src/main/scala/io/stepfunc/dnp3c/dnp3/DefaultTestDriver.scala b/src/main/scala/io/stepfunc/dnp3c/dnp3/DefaultTestDriver.scala index fe32de6..9377a95 100644 --- a/src/main/scala/io/stepfunc/dnp3c/dnp3/DefaultTestDriver.scala +++ b/src/main/scala/io/stepfunc/dnp3c/dnp3/DefaultTestDriver.scala @@ -28,6 +28,8 @@ class DefaultTestDriver( defaultLinkTimeoutMs: Int, appTimeoutMs: Int, unsolTimeoutMs: Int, + // added to the response timeouts, for the time a response takes to arrive + timingToleranceMs: Int, val clock: Clock = Clock.system, override val policies: Policies = Policies.none) extends TestDriver { @@ -199,7 +201,7 @@ class DefaultTestDriver( linkOverride: LinkOverride, timeoutMs: Option[Int]): Option[Message] = getConnection { c => val timeout = - timeoutMs.getOrElse((if (unsolicited.value) unsolTimeoutMs else appTimeoutMs) + TestDriver.readToleranceMs) + timeoutMs.getOrElse((if (unsolicited.value) unsolTimeoutMs else appTimeoutMs) + timingToleranceMs) val message = c.messageReader.read(timeout, validator, linkOverride).map(Message.parse) message.foreach(reporter.receive) message.foreach(policies.check) diff --git a/src/main/scala/io/stepfunc/dnp3c/dnp3/TestDriver.scala b/src/main/scala/io/stepfunc/dnp3c/dnp3/TestDriver.scala index 0d1904a..86fa68a 100644 --- a/src/main/scala/io/stepfunc/dnp3c/dnp3/TestDriver.scala +++ b/src/main/scala/io/stepfunc/dnp3c/dnp3/TestDriver.scala @@ -231,9 +231,6 @@ trait TestDriver { object TestDriver { - // added to the configured response timeouts, for the time a response takes to arrive - val readToleranceMs = 200 - // what every fragment of a solicited response must carry def checkSolicited(message: Message, seq: Sequence): Unit = { if (message.ctrl.uns.value) throw new Exception("Unexpected unsolicited response") diff --git a/src/test/scala/io/stepfunc/dnp3c/conformance/common/TimedActionTest.scala b/src/test/scala/io/stepfunc/dnp3c/conformance/common/TimedActionTest.scala index 3dfc334..a9046fa 100644 --- a/src/test/scala/io/stepfunc/dnp3c/conformance/common/TimedActionTest.scala +++ b/src/test/scala/io/stepfunc/dnp3c/conformance/common/TimedActionTest.scala @@ -39,8 +39,9 @@ class TimedActionTest extends AnyFunSuite with Matchers { override def close(): Unit = {} } - private val step = UnsolicitedResponseSteps.generateAndExpectEvents(holdOffMs = 0, 2000, actionWindowMs = 10000)( - AutoConfirm.No) + private val step = + UnsolicitedResponseSteps.generateAndExpectEvents(holdOffMs = 0, 2000, toleranceMs = 500, actionWindowMs = 10000)( + AutoConfirm.No) test("an armed manual action gives the DUT's response the action window as well") { val plugin = new Plugin({ @@ -50,19 +51,19 @@ class TimedActionTest extends AnyFunSuite with Matchers { val driver = new Driver(plugin) an[Exception] should be thrownBy step.run(driver) plugin.timings.toList should equal(List(ActionTiming.ArmThenAct(10000))) - driver.readTimeouts.toList should equal(List(Some(12200))) + driver.readTimeouts.toList should equal(List(Some(12500))) } test("an action performed before returning, as an automated plugin's is, gets no extra time") { val driver = new Driver(new Plugin(_ => ActionResult.Performed)) an[Exception] should be thrownBy step.run(driver) - driver.readTimeouts.toList should equal(List(Some(2200))) + driver.readTimeouts.toList should equal(List(Some(2500))) } test("an action inside a held response's window is given the time left, or isn't asked once it has run out") { val plugin = new Plugin(_ => ActionResult.Performed) val driver = new Driver(plugin) - val held = new UnconfirmedResponse(2000) + val held = new UnconfirmedResponse(2000, 500) held.record(Message(Control.request(Sequence.zero), AppFunction.response, Some(IIN.empty), Nil), driver) driver.clock.advance(100) diff --git a/src/test/scala/io/stepfunc/dnp3c/conformance/common/UnsolicitedChecksTest.scala b/src/test/scala/io/stepfunc/dnp3c/conformance/common/UnsolicitedChecksTest.scala index d9a45ea..f00a244 100644 --- a/src/test/scala/io/stepfunc/dnp3c/conformance/common/UnsolicitedChecksTest.scala +++ b/src/test/scala/io/stepfunc/dnp3c/conformance/common/UnsolicitedChecksTest.scala @@ -68,7 +68,7 @@ class UnsolicitedChecksTest extends AnyFunSuite with Matchers { test("a retry must come one confirm timeout after the response, within the tolerance") { def retryAfter(intervalMs: Option[Long]): (Boolean, Option[Int]) = { - val held = new UnconfirmedResponse(2000) + val held = new UnconfirmedResponse(2000, 500) val dut = new Dut(List(intervalMs.map(_ => unsolicited)), intervalMs.getOrElse(2500L)) held.record(unsolicited, dut) val passed = scala.util.Try(held.expectRetry(MessageValidation.none).run(dut)).isSuccess @@ -175,7 +175,11 @@ class UnsolicitedChecksTest extends AnyFunSuite with Matchers { override def generateUnsolicitedEvents(reporter: PluginReporter, timing: ActionTiming): ActionResult = ActionResult.Performed } - val step = UnsolicitedResponseSteps.generateAndExpectEvents(holdOffMs = 0, 2000, actionWindowMs = 0)(AutoConfirm.No) + val step = UnsolicitedResponseSteps.generateAndExpectEvents( + holdOffMs = 0, + 2000, + toleranceMs = 500, + actionWindowMs = 0)(AutoConfirm.No) def dut(response: Message) = new Dut(List(Some(response)), plugin = plugin) def withObjects(objects: String) = unsolicited.copy(headers = Message.parse(Hex.from("C0 81 00 00 " + objects)).headers) diff --git a/src/test/scala/io/stepfunc/dnp3c/conformance/v27/PrimaryFramesTest.scala b/src/test/scala/io/stepfunc/dnp3c/conformance/v27/PrimaryFramesTest.scala index 7af2ff7..de9912f 100644 --- a/src/test/scala/io/stepfunc/dnp3c/conformance/v27/PrimaryFramesTest.scala +++ b/src/test/scala/io/stepfunc/dnp3c/conformance/v27/PrimaryFramesTest.scala @@ -50,6 +50,7 @@ class PrimaryFramesTest extends AnyFunSuite with Matchers { 1000, 1000, 1000, + 500, new VirtualClock) step.run(driver) line.writes.toList should equal(List(bytes)) diff --git a/src/test/scala/io/stepfunc/dnp3c/conformance/v27/Procedure8_11_2_1Test.scala b/src/test/scala/io/stepfunc/dnp3c/conformance/v27/Procedure8_11_2_1Test.scala index 4d38504..1650e90 100644 --- a/src/test/scala/io/stepfunc/dnp3c/conformance/v27/Procedure8_11_2_1Test.scala +++ b/src/test/scala/io/stepfunc/dnp3c/conformance/v27/Procedure8_11_2_1Test.scala @@ -5,7 +5,7 @@ package io.stepfunc.dnp3c.conformance.v27 import io.stepfunc.dnp3c.conformance.Run import io.stepfunc.dnp3c.conformance.api.Options -import io.stepfunc.dnp3c.conformance.api.options.{ OutstationOptions, UnsolicitedOptions } +import io.stepfunc.dnp3c.conformance.api.options.{ OutstationOptions, TestOptions, UnsolicitedOptions } import io.stepfunc.dnp3c.dnp3._ import io.stepfunc.dnp3c.dnp3.app._ import io.stepfunc.dnp3c.dnp3.link.FrameValidator @@ -87,15 +87,15 @@ class Procedure8_11_2_1Test extends AnyFunSuite with Matchers { private val responseTimeoutMs = 2000 // a read's default timeout: the response timeout plus the driver's tolerance - private val defaultResponseTimeoutMs = responseTimeoutMs + TestDriver.readToleranceMs + private val defaultResponseTimeoutMs = responseTimeoutMs + TestOptions.timingToleranceMs.default test("step 30 waits for an unsolicited response to the events as long as the DUT could take to send one") { val plugin = new Plugin val dut = new Dut(plugin, 5000) val options = Options.from(Map(UnsolicitedOptions.holdOffMs.id -> "3000")) Run.passing(Procedure8_11_2_1, dut, options) - // the hold-off, the confirm timeout and a 200 ms margin - dut.timeoutsAfterEvents.toList should equal(List(Some(8200))) + // the hold-off, the confirm timeout and the default timing tolerance + dut.timeoutsAfterEvents.toList should equal(List(Some(8500))) } test("each unsolicited response after the first is a retry, one confirm timeout after the one before") { diff --git a/src/test/scala/io/stepfunc/dnp3c/conformance/v27/SecondFragmentTest.scala b/src/test/scala/io/stepfunc/dnp3c/conformance/v27/SecondFragmentTest.scala index 51a9c68..ca10f4c 100644 --- a/src/test/scala/io/stepfunc/dnp3c/conformance/v27/SecondFragmentTest.scala +++ b/src/test/scala/io/stepfunc/dnp3c/conformance/v27/SecondFragmentTest.scala @@ -38,7 +38,7 @@ class SecondFragmentTest extends AnyFunSuite with Matchers { // runs the step, then confirms the fragment it holds, to see which one that is private def run(dut: Dut): List[(AppFunction, Int)] = { - val pending = new UnconfirmedResponse(5000) + val pending = new UnconfirmedResponse(5000, 500) Procedure8_9_2_2.readSecondFragment(pending).run(dut) pending.confirm.run(dut) dut.written.toList diff --git a/src/test/scala/io/stepfunc/dnp3c/conformance/v27/SilenceWaitsTest.scala b/src/test/scala/io/stepfunc/dnp3c/conformance/v27/SilenceWaitsTest.scala index a84d8bc..a1afcb2 100644 --- a/src/test/scala/io/stepfunc/dnp3c/conformance/v27/SilenceWaitsTest.scala +++ b/src/test/scala/io/stepfunc/dnp3c/conformance/v27/SilenceWaitsTest.scala @@ -126,7 +126,7 @@ class SilenceWaitsTest extends AnyFunSuite with Matchers { val settings = Map(UnsolicitedOptions.holdOffMs.id -> "500", UnsolicitedOptions.unsolicitedConfirmTimeoutMs.id -> "2000") def eventWaits(procedure: ProcedureDefinition) = - runEachStep(procedure, settings).unsolicitedWaits.count(_.contains(2700)) + runEachStep(procedure, settings).unsolicitedWaits.count(_.contains(3000)) // 8.11.2.6: after the events, and after the request to enable unsolicited responses eventWaits(Procedure8_11_2_6) should equal(2) // 8.11.2.2: before unsolicited responses are enabled, when they are, and for the other classes' events diff --git a/src/test/scala/io/stepfunc/dnp3c/dnp3/DefaultTestDriverTest.scala b/src/test/scala/io/stepfunc/dnp3c/dnp3/DefaultTestDriverTest.scala index dfdc3d8..5857dbe 100644 --- a/src/test/scala/io/stepfunc/dnp3c/dnp3/DefaultTestDriverTest.scala +++ b/src/test/scala/io/stepfunc/dnp3c/dnp3/DefaultTestDriverTest.scala @@ -60,6 +60,7 @@ class DefaultTestDriverTest extends AnyFunSuite with Matchers { 1000, 1000, 1000, + 500, new VirtualClock) test("a reconnected DUT starts its FCB at 1 again") { diff --git a/src/test/scala/io/stepfunc/dnp3c/dnp3/NetworkDriverTest.scala b/src/test/scala/io/stepfunc/dnp3c/dnp3/NetworkDriverTest.scala index 9e67dec..1954db4 100644 --- a/src/test/scala/io/stepfunc/dnp3c/dnp3/NetworkDriverTest.scala +++ b/src/test/scala/io/stepfunc/dnp3c/dnp3/NetworkDriverTest.scala @@ -30,7 +30,8 @@ class NetworkDriverTest extends AnyFunSuite with Matchers { UInt16LE(1024), 200, 1000, - 1000) + 1000, + 500) // a server that handles one connection in the background; what the handler returns completes the future private def serve[A](handle: Socket => A): (InetSocketAddress, CompletableFuture[A]) = {