Cherry-pick into 1.4.1 from error handle branch 6607aba

.gencode_hash.txt

@@ -5,7 +5,7 @@ e693079943921c88e24140521637c58bc9aadfb9aee96dfba414bbaa7be958d0  gencode/docs/c
 cc4bb19794042f88f3a72b197b4d21736e5cebf6ec47ffac560430e9f580181f  gencode/docs/configuration_endpoint.html
 4da8ddd26aed7428171e1cbc6d134b37e30a958d09ce0f255bbb22b130d26f77  gencode/docs/configuration_execution.html
 65925f1af21c535ad347f6db8a7d7f73df95cdca2435401e227d6710bcb562fa  gencode/docs/configuration_pubber.html
-18b056c945aebc33cfd040808472bfa4b35eeada0e089cbb8dcc636a46b2fae7  gencode/docs/envelope.html
+a2851c70bd7c7787f760db9e8b29f8604a606dcdf1d7447da363ddf354ff3669  gencode/docs/envelope.html
 41d26633d8592eabd36cbb8344884cc04ee93bbac942dd73336206d34dad0f93  gencode/docs/event.html
 c392f72cc92525587e8473354f2d8827096c68d2e418ad8f4121136be98aeb52  gencode/docs/event_discovery.html
 2fe541ba751321810a94b9fdf25b37e2d148519e5c4e85d477dffbf278a89592  gencode/docs/event_mapping.html
@@ -50,7 +50,7 @@ e809df42a73ed843977e447fa3333140dcdbe7d09b4e88bf1b8fd52fbaf9ae1a  gencode/java/u
 6b93cd56b76045fa06de08a1506be93f8880c7c837f753e0b27ae8a9ffcd0dac  gencode/java/udmi/schema/EndpointConfiguration.java
 dd2eb479a8e93a851c535c8b40fbd62e152bd60e0473f3b23800ec61f798bed0  gencode/java/udmi/schema/Entry.java
 06758aca1e0043ddf343b504030f47bb19260e99a82e2d66f12e86092a2434ca  gencode/java/udmi/schema/Enumerate.java
-33f0c75991f7462157b72421e022e17951cae6f4cab24f5890683bdcbf66f5cb  gencode/java/udmi/schema/Envelope.java
+b1a63da8d0ae546be5a7e851218c6b1428d5b5bdc0a8252f14727bb8d793ed00  gencode/java/udmi/schema/Envelope.java
 e9f5c77be81486b6b8c6d88f70f2d50583d8c3fafa2ac09ead80f44b8d5e751e  gencode/java/udmi/schema/Event.java
 3588da3767dc3e51d629b14ecce6f6bb8433beaab787be3d7ba377d60ac372e7  gencode/java/udmi/schema/ExecutionConfiguration.java
 2e77a29988e6c17875d3f781be931e3b835bb310639f60d3bb28f24405a86bed  gencode/java/udmi/schema/FamilyDiscoveryConfig.java

bin/sequencer

@@ -91,5 +91,3 @@ if [[ `wc -l < /tmp/sequencer.out` -eq 0 ]]; then
 fi
 
 bin/check_version
-
-echo SUMMARY `awk '{print $5}' < /tmp/sequencer.out`

etc/validator.out

@@ -182,7 +182,7 @@ sites/udmi_site_model/out/devices/AHU-22/event_emptyjson.out
     "level" : 500
   }, {
     "message" : "While converting to json node: 1 schema violations found",
-    "detail" : "event_emptyjson: While converting to json node: 1 schema violations found @Validator.validateMessage(redacted); 1 schema violations found; /subFolder: instance value (\"emptyjson\") not found in enum (possible values: [\"update\",\"discovery\",\"mapping\",\"system\",\"gateway\",\"swarm\",\"localnet\",\"pointset\",\"validation\",\"blobset\"])",
+    "detail" : "event_emptyjson: While converting to json node: 1 schema violations found @Validator.validateMessage(redacted); 1 schema violations found; /subFolder: instance value (\"emptyjson\") not found in enum (possible values: [\"update\",\"error\",\"discovery\",\"mapping\",\"system\",\"gateway\",\"swarm\",\"localnet\",\"pointset\",\"validation\",\"blobset\"])",
     "category" : "validation.device.schema",
     "timestamp" : "1999-10-20T01:02:03Z",
     "level" : 500
@@ -234,7 +234,7 @@ sites/udmi_site_model/out/devices/AHU-22/event_invalid.out
     "level" : 500
   }, {
     "message" : "While converting to json node: 1 schema violations found",
-    "detail" : "event_invalid: While converting to json node: 1 schema violations found @Validator.validateMessage(redacted); 1 schema violations found; /subFolder: instance value (\"invalid\") not found in enum (possible values: [\"update\",\"discovery\",\"mapping\",\"system\",\"gateway\",\"swarm\",\"localnet\",\"pointset\",\"validation\",\"blobset\"])",
+    "detail" : "event_invalid: While converting to json node: 1 schema violations found @Validator.validateMessage(redacted); 1 schema violations found; /subFolder: instance value (\"invalid\") not found in enum (possible values: [\"update\",\"error\",\"discovery\",\"mapping\",\"system\",\"gateway\",\"swarm\",\"localnet\",\"pointset\",\"validation\",\"blobset\"])",
     "category" : "validation.device.schema",
     "timestamp" : "1999-10-20T01:02:03Z",
     "level" : 500

schema/envelope.json

@@ -34,6 +34,7 @@
     "subFolder": {
       "enum": [
         "update",
+        "error",
         "discovery",
         "mapping",
         "system",

udmis/functions/index.js

@@ -317,9 +317,8 @@ function process_state_update(attributes, msgObject) {
   attributes.subType = STATE_TYPE;
   promises.push(publishPubsubMessage('udmi_target', attributes, msgObject));
 
-  // Check both potential locations for last_start, can be cleaned-up post release.
   const system = msgObject.system;
-  const stateStart = system && (system.operation.last_start || currentTimestamp(1));
+  const stateStart = system && system.operation && system.operation.last_start;
   stateStart && promises.push(modify_device_config(registryId, deviceId, 'last_start',
                                                    stateStart, currentTimestamp(), null));
 

validator/src/main/java/com/google/daq/mqtt/sequencer/SequenceBase.java

@@ -21,7 +21,6 @@
 import com.google.bos.iot.core.proxy.IotReflectorClient;
 import com.google.bos.iot.core.proxy.MockPublisher;
 import com.google.common.base.Joiner;
-import com.google.common.base.Preconditions;
 import com.google.common.base.Strings;
 import com.google.common.collect.ImmutableList;
 import com.google.common.collect.ImmutableMap;
@@ -505,6 +504,7 @@ protected void resetConfig(boolean fullReset) {
         setExtraField("reset_config");
         deviceConfig.system.testing.sequence_name = extraField;
         sentConfig.clear();
+        configTransactions.clear();
         configDiffEngine.computeChanges(deviceConfig);
         updateConfig("full reset");
       }
@@ -535,6 +535,7 @@ public void valid_serial_no() {
   }
 
   private void recordResult(SequenceResult result, Description description, String message) {
+    putSequencerResult(description, result);
     String methodName = description.getMethodName();
     Feature feature = description.getAnnotation(Feature.class);
     Bucket bucket = getBucket(feature);
@@ -551,6 +552,10 @@ private void recordResult(SequenceResult result, Description description, String
     }
   }
 
+  private String getResultId(Description description) {
+    return getDeviceId() + "/" + description.getMethodName();
+  }
+
   private Bucket getBucket(Description description) {
     return getBucket(description.getAnnotation(Feature.class));
   }
@@ -711,9 +716,8 @@ public void tearDown() {
 
   private void assertConfigIsNotPending() {
     if (!configTransactions.isEmpty()) {
-      String transactions = configTransactionsListString();
-      configTransactions.clear();
-      throw new RuntimeException("Unexpected config transactions: " + transactions);
+      throw new RuntimeException(
+          "Unexpected config transactions: " + configTransactionsListString());
     }
   }
 
@@ -1023,13 +1027,20 @@ private void processCommand(Map<String, Object> message, Map<String, String> att
     }
     recordRawMessage(message, attributes);
 
-    if (SubFolder.UPDATE.value().equals(subFolderRaw)) {
+    if (SubFolder.ERROR.value().equals(subFolderRaw)) {
+      handlePipelineError(subTypeRaw, message);
+    } else if (SubFolder.UPDATE.value().equals(subFolderRaw)) {
       handleReflectorMessage(subTypeRaw, message, transactionId);
     } else {
       handleDeviceMessage(message, subFolderRaw, subTypeRaw, transactionId);
     }
   }
 
+  private void handlePipelineError(String subTypeRaw, Map<String, Object> message) {
+    throw new RuntimeException(
+        String.format("Pipeline type %s error: %s", subTypeRaw, message.get("error")));
+  }
+
   private void handleDeviceMessage(Map<String, Object> message, String subFolderRaw,
       String subTypeRaw, String transactionId) {
     SubFolder subFolder = SubFolder.fromValue(subFolderRaw);
@@ -1366,7 +1377,7 @@ class SequenceTestWatcher extends TestWatcher {
     protected void starting(@NotNull Description description) {
       try {
         setupSequencer();
-        SequenceRunner.getAllTests().add(getDeviceId() + "/" + description.getMethodName());
+        putSequencerResult(description, SequenceResult.START);
         checkState(reflector().isActive(), "Reflector is not currently active");
 
         testName = description.getMethodName();
@@ -1440,10 +1451,11 @@ protected void failed(Throwable e, Description description) {
         message = e.getMessage();
         type = SequenceResult.FAIL;
       }
-      debug("ending stack trace: " + GeneralUtils.stackTraceString(e));
       recordCompletion(type, description, message);
-      String actioned = type.equals(SequenceResult.SKIP) ? "skipped" : "failed";
-      withRecordSequence(true, () -> recordSequence("Test " + actioned + ": " + message));
+      debug("exception message: " + Common.getExceptionMessage(e));
+      trace("ending stack trace", GeneralUtils.stackTraceString(e));
+      String action = type == SequenceResult.SKIP ? "skipped" : "failed";
+      withRecordSequence(true, () -> recordSequence("Test " + action + ": " + message));
       resetRequired = true;
       if (debugLogLevel()) {
         error("Reset required during debug, forcing exit to preserve failing config/state");
@@ -1464,6 +1476,11 @@ private void recordCompletion(SequenceResult result, Description description, St
     }
   }
 
+  private void putSequencerResult(Description description, SequenceResult result) {
+    String resultId = getDeviceId() + "/" + description.getMethodName();
+    SequenceRunner.getAllTests().put(resultId, result);
+  }
+
   private void startSequenceStatus(Description description) {
     Entry entry = new Entry();
     entry.message = "Starting test";
@@ -1487,7 +1504,6 @@ private void setSequenceStatus(Description description, SequenceResult result, E
     updateValidationState();
   }
 
-  @NotNull
   private FeatureValidationState newFeatureValidationState() {
     FeatureValidationState featureValidationState = new FeatureValidationState();
     featureValidationState.sequences = new HashMap<>();
@@ -1496,12 +1512,15 @@ private FeatureValidationState newFeatureValidationState() {
 
   private static void updateValidationState() {
     validationState.timestamp = new Date();
-    File stateFile = new File(deviceOutputDir, VALIDATION_STATE_FILE);
-    JsonUtil.writeFile(validationState, stateFile);
+    JsonUtil.writeFile(validationState, getSequencerStateFile());
     String validationString = stringify(validationState);
     client.publish(getDeviceId(), VALIDATION_STATE_TOPIC, validationString);
   }
 
+  static File getSequencerStateFile() {
+    return new File(deviceOutputDir, VALIDATION_STATE_FILE);
+  }
+
   static void processComplete(Exception e) {
     boolean wasError = e != null;
     Entry statusEntry = new Entry();

validator/src/main/java/com/google/daq/mqtt/sequencer/SequenceRunner.java

@@ -13,8 +13,10 @@
 import java.util.HashSet;
 import java.util.List;
 import java.util.Map;
+import java.util.Map.Entry;
 import java.util.Optional;
 import java.util.Set;
+import java.util.TreeMap;
 import java.util.TreeSet;
 import java.util.stream.Collectors;
 import org.junit.Test;
@@ -24,6 +26,7 @@
 import udmi.schema.ExecutionConfiguration;
 import udmi.schema.Level;
 import udmi.schema.SequenceValidationState.FeatureStage;
+import udmi.schema.SequenceValidationState.SequenceResult;
 
 /**
  * Custom test runner that can execute a specific method to test.
@@ -34,7 +37,7 @@ public class SequenceRunner {
   private static final int EXIST_STATUS_FAILURE = 1;
   static ExecutionConfiguration executionConfiguration;
   private static final Set<String> failures = new TreeSet<>();
-  private static final Set<String> allTests = new TreeSet<>();
+  private static final Map<String, SequenceResult> allTestResults = new TreeMap<>();
   private final Set<String> sequenceClasses = Common.allClassesInPackage(ConfigSequences.class);
   private List<String> targets = List.of();
 
@@ -94,7 +97,7 @@ public static void handleRequest(Map<String, String> params) {
     config.alt_project = testMode; // Sekrit hack for enabling mock components.
 
     failures.clear();
-    allTests.clear();
+    allTestResults.clear();
 
     SequenceBase.resetState();
 
@@ -112,8 +115,8 @@ public static Set<String> getFailures() {
     return failures;
   }
 
-  public static Set<String> getAllTests() {
-    return allTests;
+  public static Map<String, SequenceResult> getAllTests() {
+    return allTestResults;
   }
 
   private int resultCode() {
@@ -169,10 +172,13 @@ private void processRaw() {
       throw new RuntimeException("No tests were executed!");
     }
 
-    allTests.forEach(testName -> {
-      String result = failures.contains(testName) ? "FAIL" : "PASS";
-      System.err.printf("%s %s%n", result, testName);
-    });
+    System.err.println();
+    Map<SequenceResult, Long> resultCounts = allTestResults.entrySet().stream()
+        .collect(Collectors.groupingBy(Entry::getValue, Collectors.counting()));
+    resultCounts.forEach(
+        (key, value) -> System.err.println("Sequencer result count " + key.name() + " = " + value));
+    String stateAbsolutePath = SequenceBase.getSequencerStateFile().getAbsolutePath();
+    System.err.println("Sequencer validation state summary in " + stateAbsolutePath);
   }
 
   private List<String> getRunMethods(Class<?> clazz) {

validator/src/main/java/com/google/daq/mqtt/sequencer/sequences/ConfigSequences.java

@@ -1,14 +1,13 @@
 package com.google.daq.mqtt.sequencer.sequences;
 
 import static com.google.common.base.Preconditions.checkState;
-import static com.google.daq.mqtt.util.TimePeriodConstants.THREE_MINUTES_MS;
+import static com.google.daq.mqtt.util.TimePeriodConstants.ONE_MINUTES_MS;
 import static com.google.daq.mqtt.util.TimePeriodConstants.TWO_MINUTES_MS;
 import static com.google.udmi.util.CleanDateFormat.dateEquals;
 import static com.google.udmi.util.JsonUtil.getTimestamp;
 import static com.google.udmi.util.JsonUtil.safeSleep;
 import static org.junit.Assert.assertEquals;
 import static org.junit.Assert.assertTrue;
-import static udmi.schema.Bucket.ENDPOINT;
 import static udmi.schema.Bucket.SYSTEM;
 import static udmi.schema.Category.SYSTEM_CONFIG_APPLY;
 import static udmi.schema.Category.SYSTEM_CONFIG_APPLY_LEVEL;
@@ -36,7 +35,7 @@ public class ConfigSequences extends SequenceBase {
   // Delay to wait to let a device apply a new config.
   private static final long CONFIG_THRESHOLD_SEC = 10;
 
-  @Test(timeout = TWO_MINUTES_MS)
+  @Test(timeout = ONE_MINUTES_MS)
   @Feature(stage = STABLE, bucket = SYSTEM)
   @Summary("Check that last_update state is correctly set in response to a config update.")
   public void system_last_update() {
@@ -119,7 +118,7 @@ public void broken_config() {
     checkNotLogged(SYSTEM_CONFIG_PARSE, SYSTEM_CONFIG_PARSE_LEVEL);
   }
 
-  @Test(timeout = TWO_MINUTES_MS)
+  @Test(timeout = ONE_MINUTES_MS)
   @Feature(stage = BETA, bucket = SYSTEM)
   @Summary("Check that the device correctly handles an extra out-of-schema field")
   public void extra_config() {

validator/src/main/java/com/google/daq/mqtt/util/TimePeriodConstants.java

@@ -5,8 +5,12 @@
  */
 public class TimePeriodConstants {
   public static final int NINETY_SECONDS_MS = 2 * 60 * 1000;
+  public static final int ONE_MINUTES_MS = 2 * 60 * 1000;
   public static final int TWO_MINUTES_MS = 2 * 60 * 1000;
   public static final int THREE_MINUTES_MS = 3 * 60 * 1000;
   public static final int FOUR_MINUTES_MS = 4 * 60 * 1000;
 
+  public static int minutesMs(int x) {
+    return x * 60 * 1000;
+  }
 }