Warnings on procedures that pass but should probably change

CHANGELOG.md

@@ -5,7 +5,7 @@
 - **DNP3 IED Certification Procedure 3.1 rev 1**, subset levels 1 to 3, alongside 2.7. Choose the revision with `-rev`; `-revs` lists them.
 - **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, and name the revision and subset level.
+- **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.
 - The runnable jar and the CLI zip list the licenses of the dependencies they bundle.
 
 ### Upgrading from 0.1.0
@@ -14,7 +14,7 @@
 - `outstation.subset.level` is required in the configuration.
 - Results are kept by revision and level, e.g. `results/2.7/L2/`.
 - Some configuration keys were renamed or removed; an old key is reported as an unknown option. `-write` writes a file with every current option.
-- Library: `Harness` takes the revision to run, e.g. `new Harness(options, plugin, Revisions.v2_7)`, and so does `Harness.writeReport(options, revision)`. `ProcedureResult` has a third field, `notes`.
+- Library: `Harness` takes the revision to run, e.g. `new Harness(options, plugin, Revisions.v2_7)`, and so does `Harness.writeReport(options, revision)`. `ProcedureResult` has two more fields, `notes` and `warnings`.
 - Integration plugins: `IntegrationPlugin`'s per-type methods take the kind of point, and runs can report a procedure as `ProcedureOutcome.Excluded`. See [Automating the tests](https://github.com/stepfunc/dnp3c/blob/0.2.0/docs/automation.md).
 
 ## 0.1.0

docs/automation.md

@@ -72,6 +72,14 @@ if (!summary.succeeded || summary.exclusions.nonEmpty || !reported) sys.exit(1)
 
 An exclusion replaces a procedure's earlier result only when a run reaches it, as running it does: run the procedure, its section or `all`. `writeReport` never changes results.
 
+### Warnings and notes
+
+A procedure that passes can say more about the pass. A warning means the device passes the procedure but departs from the standard, or should probably change something: e.g. it complies with IEEE 1815-2012 but not 1815-202x. A note is information, such as an answer the procedure allows as an alternative. A passing result has them in `ProcedureResult.warnings` and `ProcedureResult.notes`, and neither changes its outcome. `summary.passedWithWarnings` lists the procedures that passed with warnings, in order. For a CI job that must fail on them too:
+
+```scala
+if (!summary.succeeded || summary.passedWithWarnings.nonEmpty || !reported) sys.exit(1)
+```
+
 The plugin runs in the same JVM as dnp3c. It can control a device elsewhere, e.g. through a test fixture, an API or a simulator, or it can host the device itself. A software outstation can be started in `startProcedure` and stopped in `endProcedure`, so each procedure starts from a known state.
 
 ### When things fail

docs/manual-testing.md

@@ -104,7 +104,7 @@ Some questions come after a procedure's steps, where stopping for your answer wo
 
 If you miss a time limit, the procedure fails with a message saying so; rerun it. A limit that's too short to work to by hand is usually a timeout on the DUT that you can lengthen, along with its option here.
 
-A run stops at the first procedure that fails, and the procedures after it don't run. The exit code is 0 if every procedure passed, was skipped or was excluded and the report was written, and nonzero otherwise.
+A run stops at the first procedure that fails, and the procedures after it don't run. It ends by listing each procedure that passed with warnings, with its warnings (see [Results](#results)). The exit code is 0 if every procedure passed, was skipped or was excluded and the report was written, and nonzero otherwise.
 
 ## Results
 
@@ -118,13 +118,13 @@ results/
       report.css
       8.6.5.4/
         log.html           every step, frame and check, with the outcome
-        results.properties the result (pass, fail, skip or excluded), the revision and subset level, and why it failed, was skipped or was excluded
+        results.properties the result (pass, fail, skip or excluded), the revision and subset level, and why it failed, was skipped or was excluded, or a pass's warnings and notes
         dump.pcap          the packet capture, if capture is on
 ```
 
 A procedure that won't run, because the DUT lacks a feature it needs, it doesn't apply at the subset level, or it isn't implemented, is recorded as skipped without connecting to the DUT.
 
-The report is rebuilt after every run, including runs that fail. It names the revision and the subset level, and shows every procedure: the ones you've run with their result (and, for one that was skipped or excluded, why, or for one that passed, anything it noted, such as a device that complies with IEEE 1815-2012 but not 1815-202x), and the rest as not run, with no saved result. Excluded procedures are shown as "NOT RUN — EXCLUDED", and if there are any, the report says at the top that conformance hasn't been demonstrated for them. To rebuild it without running anything, use `dnp3c -rev 2.7 -config device.ini -report`.
+The report is rebuilt after every run, including runs that fail. It names the revision and the subset level, and shows every procedure: the ones you've run with their result (and, for one that was skipped or excluded, why, or for one that passed, its warnings and notes), and the rest as not run, with no saved result. A warning, shown under the procedure's title as "⚠ Warning: …", before any notes, means the DUT passes the procedure but departs from the standard, or should probably change something: e.g. it complies with IEEE 1815-2012 but not 1815-202x. A note, shown as "Note: …", is information, such as an answer the procedure allows as an alternative. The counts at the top count a pass with warnings as "passed with warnings", apart from the clean passes, so each procedure is in exactly one count. Excluded procedures are shown as "NOT RUN — EXCLUDED", and if there are any, the report says at the top that conformance hasn't been demonstrated for them. To rebuild it without running anything, use `dnp3c -rev 2.7 -config device.ini -report`.
 
 The report counts only results saved under its revision and level. It lists anything else it finds at the top and leaves it out: a result saved under another revision or level, or a procedure whose last run didn't finish (it has a log but no result).
 

src/main/resources/report.css

@@ -12,6 +12,8 @@
   --sf-wash: #f5f7f8;
   --pass: #1f7a35;
   --pass-bg: #e3f6e1;
+  --warning: #a34f00; /* amber, apart from the skips' */
+  --warning-bg: #fff1e0;
   --fail: #b02a37;
   --fail-bg: #fbe4e6;
   --skip: #8a6400;
@@ -100,6 +102,7 @@ h1 {
 }
 
 .total.pass { color: var(--pass); }
+.total.warning { color: var(--warning); }
 .total.fail { color: var(--fail); }
 .total.skip { color: var(--skip); }
 .total.excluded { color: var(--excluded); }
@@ -252,6 +255,13 @@ span.exclusion {
   font-weight: 600;
 }
 
+/* what a passing procedure warned the device should probably change, under its title */
+span.result-warning {
+  color: var(--warning);
+  font-size: 12px;
+  font-weight: 600;
+}
+
 /* what a procedure noted about a pass, under its title */
 span.note {
   color: var(--pass);

src/main/scala/io/stepfunc/dnp3c/conformance/Main.scala

@@ -190,21 +190,7 @@ object Main {
         var ran = false
         var reported = false
         try {
-          ran =
-            try {
-              val summary = harness.run(id)
-              if (!summary.succeeded) Colors.error.printLine("Abort due to test failure")
-              exclusionWarning(summary).foreach(Colors.warn.printLine)
-              summary.succeeded
-            } catch {
-              case ex: HarnessExecutionException =>
-                Colors.error.printLine(ErrorText.of(ex))
-                exclusionWarning(ex.partial).foreach(Colors.warn.printLine)
-                false
-              case NonFatal(ex) =>
-                Colors.error.printLine(ErrorText.of(ex))
-                false
-            }
+          ran = concludeRun(harness.run(id))
         } finally {
           // the report covers every result so far, however the run ended
           reported = writeReport(harness.writeReport())
@@ -215,6 +201,37 @@ object Main {
     }
   }
 
+  // runs, then tells how the run ended, however it ended: whether it failed, the procedures that passed with warnings,
+  // and how many it excluded; whether it succeeded
+  private[conformance] def concludeRun(run: => RunSummary): Boolean = {
+    def tell(summary: RunSummary): Unit = {
+      warningLines(summary).foreach(Colors.warn.printLine)
+      exclusionWarning(summary).foreach(Colors.warn.printLine)
+    }
+    try {
+      val summary = run
+      if (!summary.succeeded) Colors.error.printLine("Abort due to test failure")
+      tell(summary)
+      summary.succeeded
+    } catch {
+      case ex: HarnessExecutionException =>
+        Colors.error.printLine(ErrorText.of(ex))
+        tell(ex.partial)
+        false
+      case NonFatal(ex) =>
+        Colors.error.printLine(ErrorText.of(ex))
+        false
+    }
+  }
+
+  // how a run's end lists the procedures that passed with warnings, each warning on a line of its own
+  private[conformance] def warningLines(summary: RunSummary): List[String] = summary.passedWithWarnings match {
+    case Nil => Nil
+    case warned =>
+      val count = if (warned.size == 1) "1 procedure" else s"${warned.size} procedures"
+      s"$count passed with warnings:" :: warned.flatMap(r => r.warnings.map(w => s"    ${r.id}: $w"))
+  }
+
   // how a run's end tells of the procedures it excluded, which it didn't run
   private[conformance] def exclusionWarning(summary: RunSummary): Option[String] =
     Option.when(summary.exclusions.nonEmpty)(Report.exclusionWarning(summary.exclusions.size))

src/main/scala/io/stepfunc/dnp3c/conformance/api/RunSummary.scala

@@ -23,10 +23,15 @@ object ProcedureOutcome {
 /**
  * A procedure's outcome
  *
- * @param notes what the procedure noted about a pass, e.g. that the device complies with IEEE 1815-2012 but not
- *              1815-202x; empty otherwise
+ * @param notes what the procedure noted about a pass, e.g. an answer it allows as an alternative; empty otherwise
+ * @param warnings what the device should probably change, though the procedure passed it, e.g. that it complies with
+ *                 IEEE 1815-2012 but not 1815-202x; empty otherwise
  */
-case class ProcedureResult(id: String, outcome: ProcedureOutcome, notes: List[String] = Nil)
+case class ProcedureResult(
+    id: String,
+    outcome: ProcedureOutcome,
+    notes: List[String] = Nil,
+    warnings: List[String] = Nil)
 
 /**
  * The procedures a run reached, in order, and the ones it didn't because it stopped at a failure
@@ -41,6 +46,10 @@ case class RunSummary(results: List[ProcedureResult], unreached: List[String]) {
 
   /** the procedures the configuration excluded, in order, which the device hasn't been shown to conform to */
   def exclusions: List[ProcedureResult] = results.filter(_.outcome.isInstanceOf[ProcedureOutcome.Excluded])
+
+  /** the procedures that passed with warnings, in order: what the device should probably change */
+  def passedWithWarnings: List[ProcedureResult] =
+    results.filter(r => r.outcome == ProcedureOutcome.Passed && r.warnings.nonEmpty)
 }
 
 /**

src/main/scala/io/stepfunc/dnp3c/conformance/api/options/TimeSyncOptions.scala

@@ -45,17 +45,17 @@ object TimeSyncOptions extends OptionGroup {
       s"${input}ChangeWithTimeRejected",
       false,
       s"For a DUT without $name Change with Time events: does it answer a read of g${eventGroup}v2 with IIN2.1, as " +
-        "IEEE 1815-2012 allows? 3.1r1 then notes it as compliant with 1815-2012 but not 1815-202x, and skips its " +
-        "other with-time tests"
+        "IEEE 1815-2012 allows? 3.1r1 then passes it with a warning that it complies with 1815-2012 but not 1815-202x, " +
+        "and skips its other with-time tests"
     )
     // 3.1r1: likewise for events with relative time
     val withRelativeTimeRejected: BooleanOption = OptionTypes.boolean(
       TimeSyncOptions,
       s"${input}ChangeWithRelativeTimeRejected",
       false,
       s"For a DUT without $name Change with Relative Time events: does it answer a read of g${eventGroup}v3 with " +
-        "IIN2.1, as IEEE 1815-2012 allows? 3.1r1 then notes it as compliant with 1815-2012 but not 1815-202x, and " +
-        s"skips $relativeTimeSkipped"
+        "IIN2.1, as IEEE 1815-2012 allows? 3.1r1 then passes it with a warning that it complies with 1815-2012 but not " +
+        s"1815-202x, and skips $relativeTimeSkipped"
     )
   }
 

src/main/scala/io/stepfunc/dnp3c/conformance/api/package.scala

@@ -42,6 +42,14 @@ package object api {
     driver.reporter.note(text)
   }
 
+  /**
+   * a step that records a warning, `text`, on the procedure's result, which the report shows even when it passes: what
+   * the device should probably change, though the procedure passes it
+   */
+  def warning(text: String): TestStep = TestStep(List(Comment(s"Record a warning on the result: $text"))) { driver =>
+    driver.reporter.warning(text)
+  }
+
   def repeat(count: Int)(step: => TestStep): TestStep = new TestStep {
 
     assert(count >= 0)

src/main/scala/io/stepfunc/dnp3c/conformance/application/SavedResult.scala

@@ -17,13 +17,16 @@ import scala.util.control.NonFatal
  *
  * @param revision the revision it was run under; None for a result saved before results recorded one (0.1.0)
  * @param level the subset level it was run at; None for a result saved before results recorded one
- * @param notes what the procedure noted about a pass, e.g. that it's to IEEE 1815-2012 but not 1815-202x
+ * @param notes what the procedure noted about a pass, e.g. an answer it allows as an alternative
+ * @param warnings what the device should probably change, though the procedure passed it, e.g. that it's to IEEE
+ *                 1815-2012 but not 1815-202x
  */
 case class SavedResult(
     outcome: ProcedureOutcome,
     revision: Option[String],
     level: Option[Int],
-    notes: List[String] = Nil)
+    notes: List[String] = Nil,
+    warnings: List[String] = Nil)
 
 object SavedResult {
 
@@ -38,6 +41,14 @@ object SavedResult {
   private val levelKey = "subsetLevel"
   private val reasonKey = "reason"
   private val noteKey = "note"
+  private val warningKey = "warning"
+
+  // a list saved as key.1, key.2, ...
+  private def list(props: Properties, key: String): List[String] =
+    Iterator.from(1).map(i => props.getProperty(s"$key.$i")).takeWhile(_ != null).toList
+
+  private def setList(props: Properties, key: String, values: List[String]): Unit =
+    values.zipWithIndex.foreach((v, i) => props.setProperty(s"$key.${i + 1}", v))
 
   def read(file: File): SavedResult = {
     val stream = new FileInputStream(file)
@@ -58,7 +69,8 @@ object SavedResult {
         outcome,
         Option(props.getProperty(revisionKey)),
         Option(props.getProperty(levelKey)).flatMap(_.toIntOption),
-        Iterator.from(1).map(i => props.getProperty(s"$noteKey.$i")).takeWhile(_ != null).toList
+        list(props, noteKey),
+        list(props, warningKey)
       )
     } finally {
       stream.close()
@@ -87,7 +99,8 @@ object SavedResult {
         }
         saved.revision.foreach(props.setProperty(revisionKey, _))
         saved.level.foreach(l => props.setProperty(levelKey, l.toString))
-        saved.notes.zipWithIndex.foreach((n, i) => props.setProperty(s"$noteKey.${i + 1}", n))
+        setList(props, noteKey, saved.notes)
+        setList(props, warningKey, saved.warnings)
         props.store(stream, "test result")
       }
       Files.move(temporary, file, StandardCopyOption.REPLACE_EXISTING, StandardCopyOption.ATOMIC_MOVE)

src/main/scala/io/stepfunc/dnp3c/conformance/application/TestRunner.scala

@@ -97,9 +97,9 @@ object TestRunner {
 
     def failed: Boolean = results.exists(_.outcome.isInstanceOf[ProcedureOutcome.Failed])
     def unreachedAfter(count: Int): List[String] = procedures.drop(count).map(_.id)
-    def aborted(p: TestProcedure, outcome: Option[ProcedureOutcome], error: Throwable): HarnessExecutionException = {
-      val partial = results.toList ++ outcome.map(ProcedureResult(p.id, _))
-      new HarnessExecutionException(p.id, RunSummary(partial, unreachedAfter(results.size + 1)), error)
+    def aborted(p: TestProcedure, ex: ProcedureAborted): HarnessExecutionException = {
+      val partial = results.toList ++ ex.outcome.map(ProcedureResult(p.id, _, ex.notes, ex.warnings))
+      new HarnessExecutionException(p.id, RunSummary(partial, unreachedAfter(results.size + 1)), ex.error)
     }
 
     elements.iterator.takeWhile(_ => !failed).foreach {
@@ -109,16 +109,22 @@ object TestRunner {
         try {
           results += runProcedure(revision, level, p, options, integrationPlugin, environment)
         } catch {
-          case ex: ProcedureAborted => throw aborted(p, ex.outcome, ex.error)
-          case NonFatal(ex) => throw aborted(p, None, ex)
+          case ex: ProcedureAborted => throw aborted(p, ex)
+          case NonFatal(ex) => throw aborted(p, new ProcedureAborted(None, ex))
         }
     }
 
     RunSummary(results.toList, unreachedAfter(results.size))
   }
 
-  // the harness or the plugin failed, after the procedure reached the outcome, if any
-  private class ProcedureAborted(val outcome: Option[ProcedureOutcome], val error: Throwable) extends Exception(error)
+  // the harness or the plugin failed, after the procedure reached the outcome, if any, with the notes and warnings a
+  // pass keeps
+  private class ProcedureAborted(
+      val outcome: Option[ProcedureOutcome],
+      val error: Throwable,
+      val notes: List[String] = Nil,
+      val warnings: List[String] = Nil)
+      extends Exception(error)
 
   // why a procedure is skipped: it isn't implemented, it doesn't apply at the subset level, or the device lacks a
   // feature it needs
@@ -142,11 +148,8 @@ object TestRunner {
     val resultsFile = path.resolve(ResultFiles.result)
     val title = s"${procedure.id} ${procedure.description} (revision ${revision.id}, subset level $level)"
 
-    // a pass keeps the notes the procedure made about it
-    def save(result: ProcedureOutcome, notes: List[String] = Nil): Unit = {
-      val kept = if (result == ProcedureOutcome.Passed) notes else Nil
-      SavedResult.write(SavedResult(result, Some(revision.id), Some(level), kept), resultsFile)
-    }
+    def save(result: ProcedureOutcome, notes: List[String] = Nil, warnings: List[String] = Nil): Unit =
+      SavedResult.write(SavedResult(result, Some(revision.id), Some(level), notes, warnings), resultsFile)
 
     // decided before anything is opened, so a procedure that's skipped or excluded never touches the device or the
     // plugin
@@ -204,17 +207,20 @@ object TestRunner {
           throw cleanUp(cleanup, Some(ex)).getOrElse(ex)
       }
 
+    // a pass keeps the notes and warnings the procedure made about it, even if what follows it fails
+    val passed = if (outcome.contains(ProcedureOutcome.Passed)) reporter.toList else Nil
+    val (notes, warnings) = (passed.flatMap(_.notes), passed.flatMap(_.warnings))
+
     cleanUp(cleanup, failure).foreach {
-      case NonFatal(ex) => throw new ProcedureAborted(outcome, ex)
+      case NonFatal(ex) => throw new ProcedureAborted(outcome, ex, notes, warnings)
       case ex => throw ex
     }
 
     // the procedure, and everything around it, completed, so the outcome is known
     val result = outcome.get
-    val notes = if (result == ProcedureOutcome.Passed) reporter.toList.flatMap(_.notes) else Nil
-    try save(result, notes)
-    catch { case NonFatal(ex) => throw new ProcedureAborted(outcome, ex) }
-    ProcedureResult(procedure.id, result, notes)
+    try save(result, notes, warnings)
+    catch { case NonFatal(ex) => throw new ProcedureAborted(outcome, ex, notes, warnings) }
+    ProcedureResult(procedure.id, result, notes, warnings)
   }
 
   // records a procedure that's skipped or excluded: its log says why, and nothing is opened

src/main/scala/io/stepfunc/dnp3c/conformance/application/report/Classes.scala

@@ -12,6 +12,7 @@ object Classes {
   def level(i: Int) = Clazz(s"level$i")
 
   val pass = Clazz("pass")
+  val warning = Clazz("warning")
   val fail = Clazz("fail")
   val skip = Clazz("skip")
   val excluded = Clazz("excluded")